はじめに
Sinatra と Slim を使ってちょっとしたウェブアプリケーションをいくつも作っている。
gem のバージョンを上げたところで,アクセス時に
NoMethodError - undefined method `empty?' for nil:NilClass
というエラーが出るようになった。
この記事は,その原因の解明と解決の記録。
結論を先に書くと,slim が依存している temple という gem のバージョンが 0.10.0 から 0.10.1 に上がったことによって引き起こされていた。
temple の修正版が出るまでは,さしあたり,バージョンを 0.10.0 に固定することで回避できる。
記事執筆時点(2023-05-27)では,temple 側で既に修正は済んでおり,バージョン 0.10.2 のリリースを待つのみとなっている。
→ ええと,この記事を書き終わる前に無事 0.10.2 がリリースされ,本件は解決した。みなさん,0.10.2 以上にしましょう。
現象
Ruby と gem のバージョン
Ruby は以下のとおり最新版。
ruby 3.2.2 (2023-03-30 revision e51014f9c0) [arm64-darwin20]
本件に関係しそうな gem のバージョンは次のとおり。
- sinatra (3.0.6)
- slim (5.1.1)
- temple (0.10.1)
- tilt (2.1.0)
- rack (2.2.7)
- rack-protection (3.0.6)
このうち Gemfile に指定しているのは sinatra と slim だけであり,temple が関わっていると分かるまでだいぶかかった。
エラー箇所
エラーが出ていたのは Slim のテンプレートの
div class=("foo" if foo) 云々
のような箇所であった。
"foo" if foo は,式 foo の値が真であれば "foo" を返し,偽なら nil を返す。
Slim のルールでは,属性値に真な値を与えればそれが採用され,偽なら属性指定自体が無視されることになっている。
要するに式 foo の値によって,上記の Slim コードは
<div class="foo">云々</div>
と
<div>云々</div>
のどちらかになるわけだ。
NoMethodError の箇所
前節のとおり,エラーが出ていた Slim テンプレート自体には empty? は書かれていない。
そこで,バックトレースを確認することにする。
以下のようであった。
2 行目はテンプレート,3 行目は tilt といった具合。
NoMethodError - undefined method `empty?' for nil:NilClass:
/Users/XXXX/projects/sinatra/hogehoge/views/layout.slim:13:in `__tilt_2340'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/tilt-2.1.0/lib/tilt/template.rb:191:in `bind_call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/tilt-2.1.0/lib/tilt/template.rb:191:in `evaluate'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/tilt-2.1.0/lib/tilt/template.rb:109:in `render'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:852:in `render'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:862:in `block in render'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:862:in `catch'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:862:in `render'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:787:in `slim'
/Users/XXXX/projects/sinatra/regexmaster/server.rb:123:in `block in <top (required)>'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1707:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1707:in `block in compile!'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1019:in `block (3 levels) in route!'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1037:in `route_eval'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1019:in `block (2 levels) in route!'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1068:in `block in process_route'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1066:in `catch'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1066:in `process_route'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1017:in `block in route!'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1014:in `each'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1014:in `route!'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1138:in `block in dispatch!'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1109:in `catch'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1109:in `invoke'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1133:in `dispatch!'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:949:in `block in call!'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1109:in `catch'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1109:in `invoke'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:949:in `call!'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:938:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-protection-3.0.6/lib/rack/protection/xss_header.rb:20:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-protection-3.0.6/lib/rack/protection/path_traversal.rb:18:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-protection-3.0.6/lib/rack/protection/json_csrf.rb:28:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-protection-3.0.6/lib/rack/protection/base.rb:53:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-protection-3.0.6/lib/rack/protection/base.rb:53:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-protection-3.0.6/lib/rack/protection/frame_options.rb:33:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-2.2.7/lib/rack/logger.rb:17:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:254:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-2.2.7/lib/rack/head.rb:12:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-2.2.7/lib/rack/method_override.rb:24:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/show_exceptions.rb:23:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:219:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:2018:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1576:in `block in call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1792:in `synchronize'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:1576:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-2.2.7/lib/rack/tempfile_reaper.rb:15:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-2.2.7/lib/rack/lint.rb:50:in `_call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-2.2.7/lib/rack/lint.rb:38:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-2.2.7/lib/rack/show_exceptions.rb:23:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-2.2.7/lib/rack/common_logger.rb:38:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/sinatra-3.0.6/lib/sinatra/base.rb:261:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-2.2.7/lib/rack/content_length.rb:17:in `call'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/rack-2.2.7/lib/rack/handler/webrick.rb:95:in `service'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/webrick-1.8.1/lib/webrick/httpserver.rb:140:in `service'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/webrick-1.8.1/lib/webrick/httpserver.rb:96:in `run'
/Users/XXXX/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/webrick-1.8.1/lib/webrick/server.rb:310:in `block in start_thread'
バックトレースに示された箇所を順に見て empty? メソッドの出現箇所を探すことにした。
ところが,なかなか見つからない。
どうも,ライブラリーの誰かが,本当に NoMethodError が出た箇所の情報を握りつぶしているように思われた。
つまり,empty? のある箇所はバックトレースには書かれていないようなのだ。
これには参った。
原因を探る
issue
次に,「この問題は既に報告されているのではないか?」と考え,sinatra や slim のリポジトリーの issues を見に行った。
すると,olleolleolle さんという方が issue を四日前に上げられていた:
https://github.com/sinatra/sinatra/discussions/1925
そんなに最近,ということは,やはりつい最近行われた gem のアップデートで引き起こされたのか,と思った。
しかし,この issue を見ても,正直よく分からなかった。
ただ,temple のバージョンを 0.10.0 から 0.10.1 に上げたら,ということははっきりと書かれている。
試しに 0.10.0 と 0.10.1 を切り替えて実験してみると,確かにこのバージョンアップが再現条件であることが確認できた。
以下の最小再現コードを得た。
gem "sinatra", "3.0.6"
gem "slim", "5.1.1"
gem "temple", "0.10.1"
require "sinatra"
get "/" do
slim %(div class="" foo)
end
これを実行して http://localhost:4567/ にアクセスすると NoMethodError が出る。
再現条件を探る
テンプレート側の再現条件はどうだろう。
class 属性を style, lang, id など他のものにすると再現しなかった。
また,属性値を空文字列から他のもの(空ではない文字列など)にすると再現しなかった。しかし,nil や false にすると再現した。要するに,属性指定を無視するような値の場合に再現するわけだ。
sinatra や slim のバージョンを少し変えてみたが再現性は変わらなかった。
メソッドの呼び出しを遡る
バックトレースでは NoMethodError が出ている本当の箇所は分からなかったので,メソッド呼び出しを順に遡り,引数の値を見るなどして原因を探った。
なお,temple 0.10.0 → 0.10.1 が関係しているのは間違いないので,差分 を眺めることも並行して行った。
その結果,エラーを引き起こすことになった temple の箇所の変更が特定できた。
この capture_generator.new の引数にもともと **options は無かったのだが,バージョン 0.10.1 でこれが追加された。
さらに,具体的に options の何が問題だったかを調べたところ,options[:save_buffer] の値が渡っていることがマズいようだった。
さきの olleolleolle さんは sinatra への issue とは別に,temple のほうにも issue を上げられていた。
https://github.com/judofyr/temple/issues/145
そこで,こちらの issue に,調べたことを書き込んでおいた。
なお,私はどこで何が起きているかを調べただけ。それぞれの gem の仕組みについては全然分かっていない。
解決
その後,半日くらいで修正が行われた。それがこちら:
https://github.com/judofyr/temple/commit/0bdacf93e87294e6dd2935c6178071329fa2bcda
要するに,options を丸ごと渡すんではなくて,要るものだけを渡すことにしたようだ。
感想など
- ライブラリー間で引数をばぼーんと丸投げして不具合が生じる例を他でも最近見た
- 最初に例外が発生した箇所がバックトレースに無いのは調べるのがつらい
- 中身が全然理解できてなくても,どこで何が起きているか,分かる範囲で調べて報告すると役に立つかもしれない(今回役に立ったかどうかは分からない)
- ライブラリーの開発・保守は大変だと思う。すぐに直してくれてありがたかった。