simpletrace: ライブラリのスタックトレースを消すライブラリ

例えば、こういうスタックトレースをしばしば見ると思います。

$ ruby19 -ruri -e 'URI(nil)'
/home/mame/work/ruby19/local/lib/ruby/1.9.1/uri/common.rb:156:in `split': bad UR
I(is not URI?):  (URI::InvalidURIError)
        from /home/mame/work/ruby19/local/lib/ruby/1.9.1/uri/common.rb:174:in `p
arse'
        from /home/mame/work/ruby19/local/lib/ruby/1.9.1/uri/common.rb:626:in `p
arse'
        from /home/mame/work/ruby19/local/lib/ruby/1.9.1/uri/common.rb:724:in `U
RI'
        from -e:1:in `<main>'

うじゃうじゃしてるけど、この中で知りたい情報は、例外メッセージと最後の行くらいなもんです。
この程度なら許容範囲ですが、gem を使ってるとしばしばひどいのに出くわします。例えば sequel 。

$ ruby19 -rsequel -e 'DB = Sequel.connect("sqlite:/"); DB[:foo].to_a'
/home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sqlite3-ruby-1.2.4/lib/sql
ite3/errors.rb:62:in `check': SQLite3::SQLException: no such table: foo (Sequel:
:DatabaseError)
        from /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sqlite3-ruby-
1.2.4/lib/sqlite3/statement.rb:40:in `initialize'
        from /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sqlite3-ruby-
1.2.4/lib/sqlite3/database.rb:154:in `new'
        from /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sqlite3-ruby-
1.2.4/lib/sqlite3/database.rb:154:in `prepare'
        from /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sqlite3-ruby-
1.2.4/lib/sqlite3/database.rb:245:in `query'
        from /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sequel-3.1.0/
lib/sequel/adapters/sqlite.rb:78:in `block in execute'
        from /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sequel-3.1.0/
lib/sequel/adapters/sqlite.rb:93:in `block in _execute'
        from /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sequel-3.1.0/
lib/sequel/connection_pool.rb:108:in `hold'
        from /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sequel-3.1.0/
lib/sequel/database.rb:460:in `synchronize'
        from /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sequel-3.1.0/
lib/sequel/adapters/sqlite.rb:93:in `_execute'
        from /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sequel-3.1.0/
lib/sequel/adapters/sqlite.rb:78:in `execute'
        from /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sequel-3.1.0/
lib/sequel/dataset.rb:277:in `execute'
        from /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sequel-3.1.0/
lib/sequel/adapters/sqlite.rb:191:in `fetch_rows'
        from /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/sequel-3.1.0/
lib/sequel/dataset.rb:184:in `each'
        from -e:1:in `to_a'
        from -e:1:in `<main>'

うわー。
ramaze はもっとひどい。

class MainController < Ramaze::Controller
  def index
    raise
  end
end
Ramaze.start
RuntimeError:
        -e:1:in `index'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/action.rb:86:in `block in render'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/helper/aspect.rb:36:in `aspect_wrap'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/helper/aspect.rb:87:in `wrap_action_call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/action.rb:84:in `render'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/action.rb:35:in `block in call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/action.rb:117:in `wrap_in_current'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/action.rb:35:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/node.rb:295:in `block (2 levels) in action_found'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/node.rb:295:in `catch'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/node.rb:295:in `block in action_found'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/node.rb:295:in `catch'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/node.rb:295:in `action_found'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/node.rb:279:in `try_resolve'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/node.rb:264:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/urlmap.rb:46:in `block in call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/urlmap.rb:40:in `each'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/urlmap.rb:40:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/dynamap.rb:40:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/route.rb:75:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/cascade.rb:19:in `block in call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/cascade.rb:17:in `each'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/cascade.rb:17:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/current.rb:22:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/cascade.rb:19:in `block in call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/cascade.rb:17:in `each'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/cascade.rb:17:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/ramaze-2009.06.20/
lib/ramaze/app.rb:93:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/urlmap.rb:46:in `block in call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/urlmap.rb:40:in `each'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/urlmap.rb:40:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/dynamap.rb:40:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/ramaze-2009.06.20/
lib/ramaze/reloader.rb:88:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/head.rb:9:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/ramaze-2009.06.20/
lib/vendor/etag.rb:11:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/conditionalget.rb:25:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/content_length.rb:13:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/ramaze-2009.06.20/
lib/vendor/route_exceptions.rb:22:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/showstatus.rb:20:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/showexceptions.rb:24:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/commonlogger.rb:20:in `_call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/commonlogger.rb:13:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/lint.rb:47:in `_call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/lint.rb:35:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/innate-2009.06.20/
lib/innate/middleware_compiler.rb:52:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/content_length.rb:13:in `call'
        /home/mame/work/ruby19/local/lib/ruby/gems/1.9.1/gems/rack-1.0.0/lib/rac
k/handler/webrick.rb:46:in `service'
        /home/mame/work/ruby19/local/lib/ruby/1.9.1/webrick/httpserver.rb:111:in
 `service'
        /home/mame/work/ruby19/local/lib/ruby/1.9.1/webrick/httpserver.rb:70:in 
`run'
        /home/mame/work/ruby19/local/lib/ruby/1.9.1/webrick/server.rb:183:in `bl
ock in start_thread'

ひょえー。見るべきところがわかりにくいし、ターミナルがずぞぞぞぞっと流れるし、不便ですよね。


問題はライブラリの中身までトレースに出てくることでしょう。ということで、その辺省いて読みやすいトレースを出すライブラリを作ってみました。すでにありそうな気もするけど。
http://github.com/mame/simpletrace/blob/master/lib/simpletrace.rb
コピペできるくらい簡単なコードですが、一応 gem にしてみました。

$ gem install mame-simpletrace --source=http://gems.github.com/

起動時に -rsimpletrace をつければ、こんな風にシンプルなトレースが出るはず。

$ ruby19 -rsimpletrace -ruri -e 'URI(nil)'
-e:1:in `<main>': bad URI(is not URI?): nil (URI::InvalidURIError)

当然ライブラリがバグってた場合 (フツーにありえます) は逆に気づきにくくなります。が、開発中の自分のコードがバグってる確率の方が圧倒的に高いだろうということで。

関連 (するようなしないような): prettytrace