Railsのコントローラでの不可解(に見える)なエラーハンドリングについて

技術

Twitterでこのようなやりとりを見かけて、気になって眠れなかったので調べてみた。 長ったらしく説明しているので結論だけ知りたい方は下までスクロールしてください。

問題

手元ですぐ動かせる Rails5.1.1 / Ruby 2.5.0で試した。

# controller
class WelcomeController < ApplicationController
  def index
    raise ActiveRecord::RecordNotFound
  rescue => e
    raise 're raise'
  end
end

# config/route.rp
Rails.application.routes.draw do
  root to: 'welcome#index'
end

この状態でWEBにアクセスするとこうなる!!

f:id:suzan2go:20180420013817p:plain

！？ raise re raise にならん・・・まじだ rescueされてないようにみえる。

ちなみにこれをコンソールでやるとこうなる

f:id:suzan2go:20180420013930p:plain

コンソールだとちゃんと “re raise” が例外になる？！

次にコントローラの例外をRecordNotFoundでなくしてみる

# controller
class WelcomeController < ApplicationController
  def index
    raise ActiveRecordError
  rescue => e
    raise 're raise'
  end
end

f:id:suzan2go:20180420014159p:plain

するとちゃんと re raise の方が例外として上がってくる…不可解

種明かし

rescueされてないよう見えるが、本当にされてないのだろうか。 binding.pry を仕掛けてみよう

class WelcomeController < ApplicationController
  def index
    raise ActiveRecord::RecordNotFound
  rescue => e
    binding.pry
    raise 're raise'
  end
end

f:id:suzan2go:20180420014538p:plain

あれ・・・ちゃんとrescueされてますね・・・ ということは、画面上の表示がおかしいのだろうか

lib/action_dispatch/middleware/debug_exceptions.rb @ line 68 ActionDispatch::DebugExceptions#call:

    57: def call(env)
    58:   request = ActionDispatch::Request.new env
    59:   _, headers, body = response = @app.call(env)
    60:
    61:   if headers["X-Cascade"] == "pass"
    62:     body.close if body.respond_to?(:close)
    63:     raise ActionController::RoutingError, "No route matches [#{env['REQUEST_METHOD']}] #{env['PATH_INFO'].inspect}"
    64:   end
    65:
    66:   response
    67: rescue Exception => exception
 => 68:   raise exception unless request.show_exceptions?
    69:   render_exception(request, exception)
    70: end

[1] pry(#<ActionDispatch::DebugExceptions>)> exception
=> #<RuntimeError: re raise>

render_exception というエラーページを生成しているところまでちゃんと re raise のエラーが渡ってきていますね。

では render_exception の中身を見ていきましょう

# actionpack-5.1.1/lib/action_dispatch/middleware/debug_exceptions.rb

      def render_exception(request, exception)
        backtrace_cleaner = request.get_header("action_dispatch.backtrace_cleaner")
        wrapper = ExceptionWrapper.new(backtrace_cleaner, exception)
        log_error(request, wrapper)

        if request.get_header("action_dispatch.show_detailed_exceptions")
          content_type = request.formats.first

          if api_request?(content_type)
            render_for_api_request(content_type, wrapper)
          else
            render_for_browser_request(request, wrapper)
          end
        else
          raise exception
        end
      end

ExceptionWrapper.new が怪しそう。さらにこのコードを追ってみます。

# actionpack-5.1.1/lib/action_dispatch/middleware/exception_wrapper.rb

module ActionDispatch
  class ExceptionWrapper
  # 〜〜〜省略〜〜〜〜
    @@rescue_responses.merge!(
      "ActionController::RoutingError"               => :not_found,
      "AbstractController::ActionNotFound"           => :not_found,
      "ActionController::MethodNotAllowed"           => :method_not_allowed,
      "ActionController::UnknownHttpMethod"          => :method_not_allowed,
      "ActionController::NotImplemented"             => :not_implemented,
      "ActionController::UnknownFormat"              => :not_acceptable,
      "ActionController::InvalidAuthenticityToken"   => :unprocessable_entity,
      "ActionController::InvalidCrossOriginRequest"  => :unprocessable_entity,
      "ActionDispatch::Http::Parameters::ParseError" => :bad_request,
      "ActionController::BadRequest"                 => :bad_request,
      "ActionController::ParameterMissing"           => :bad_request,
      "Rack::QueryParser::ParameterTypeError"        => :bad_request,
      "Rack::QueryParser::InvalidParameterError"     => :bad_request
    )
  # 〜〜〜省略〜〜〜〜

  def initialize(backtrace_cleaner, exception)
    @backtrace_cleaner = backtrace_cleaner
    @exception = original_exception(exception)

    expand_backtrace if exception.is_a?(SyntaxError) || exception.cause.is_a?(SyntaxError)
  end

  # 〜〜〜省略〜〜〜〜

  private

      def original_exception(exception)
        if @@rescue_responses.has_key?(exception.cause.class.name)
          exception.cause
        else
          exception
        end
      end

  # 〜〜〜省略〜〜〜〜

end

読んでいくと以下のような動きになっていることがわかります。

  1. initializeで original_exception というのを呼ぶ、
  2. original_exception ではexception.cause で元々発生していた例外を見に行く
  3. それが rescue_responses に一致する場合には、それをExceptionWrapper の exception にセットする

docs.ruby-lang.org

でも、ここには ActiveRecord::NotFound に対応するものはありません。 実はここではなくて、ActiveRecodの方で拡張が行われているようです。(コードちゃんとおったわけではないけど多分これ)

# activerecord-5.1.1/lib/active_record/railtie.rb

module ActiveRecord
  # = Active Record Railtie
  class Railtie < Rails::Railtie # :nodoc:

  # 〜〜〜省略〜〜〜〜

    config.action_dispatch.rescue_responses.merge!(
      "ActiveRecord::RecordNotFound"   => :not_found,
      "ActiveRecord::StaleObjectError" => :conflict,
      "ActiveRecord::RecordInvalid"    => :unprocessable_entity,
      "ActiveRecord::RecordNotSaved"   => :unprocessable_entity
    )

  # 〜〜〜省略〜〜〜〜
end

ここまで来てやっとわかりました。例外のその前に発生していた例外が、ActiveRecord::RecordNotFound の場合には、画面上に発生した例外そのもの(今回でいうと re raise)ではなく、元々の例外であるActiveRecord::RecordNotFound が表示される。という挙動になっているようです。

　結論

実際にTweetされてる方の環境を確認したわけではないので完全なる推測ですが、以下のような状況なのではないでしょうか

  • エラーハンドリングはきちんと行われている
  • しかし特定の例外の場合には、rescue節の例外ではなく、その前に発生していた元々の例外の情報が画面に表示される
  • 上記の挙動によりActiveRecord::RecordNotFoundが rescue されていないような不可解な挙動に見えた

ちなみにこの挙動はRails3.2.0RCからあるもののようです。

Add an ExceptionWrapper that wraps an exception and provide convenien… · rails/rails@0b677b1 · GitHub

追記