rack-timeout をデフォルトで使っているとタイムアウトしたリクエストの scope が後続リクエストにも適用され得る

2 min read読了の目安(約2500字

rack-timeout をデフォルトのままで使っている人は、term_on_timeout: true にして、かつ、Puma も使っているのであれば clustered mode で動かしましょう。


rack-timeout を term_on_timeout: false (デフォルト) のまま使っていると、コード上 User.count と書いているにも関わらず、リクエスト前の User.where(name: "foo") が適用され続け、User.where(name: "foo").count に化けてしまう可能性があります。

以下のコードが再現コードです。

require "bundler/inline"

gemfile do
  source "https://rubygems.org"

  gem "rails", "6.1.3.1"
  gem "sqlite3"
  gem "rack-timeout", require: "rack/timeout/base"
end

require "rack/test"
require "active_record/railtie"
require "action_controller/railtie"

ActiveRecord::Base.establish_connection(adapter: "sqlite3", database: ":memory:")
ActiveRecord::Base.logger = Logger.new(File::NULL)
ActiveRecord::Base.logger.level = Logger::ERROR

ActiveRecord::Schema.define do
  create_table :users, force: true do |t|
    t.string :name
  end
end

class User < ActiveRecord::Base
  scope :sleep_a_while, -> { all.tap { sleep(rand / 1000000.0) } }
end

User.create!(name: "foo")
User.create!(name: "bar")

class TestApp < Rails::Application
  config.root = __dir__
  config.hosts << "example.org"
  config.session_store :cookie_store, key: "cookie_store_key"
  secrets.secret_key_base = "secret_key_base"

  config.logger = ActiveRecord::Base.logger
  Rails.logger  = config.logger

  config.middleware.insert_before Rack::Runtime, Rack::Timeout, service_timeout: 0.1

  config.exceptions_app = ->(*) { [500, {}, ['']] }

  routes.draw do
    get "/" => "test#index"
    get "/timeout" => "test#timeout"
  end
end

class TestController < ActionController::Base
  include Rails.application.routes.url_helpers

  def index
    render plain: User.count
  end

  def timeout
    loop do
      User.where(name: "foo").sleep_a_while
    end
  end
end

require "minitest/autorun"

class BugTest < Minitest::Test
  include Rack::Test::Methods

  def test_index
    get "/"

    # Make sure User.count is 2
    assert_equal "2", last_response.body

    until last_response.body == "1"
      get "/timeout"

      get "/"
    end

    get "/"
    # User.count must be always 2 but it's now 1
    assert_equal "2", last_response.body
  end

  private
    def app
      Rails.application
    end
end

これは Timeout 時に ensure が実行されない可能性があるためです[1]
なお、Timeout 時に起きる問題については Rails は考慮しない方針としているようです[2]
また、rack-timeout は歴史的に例外を投げるにとどめていたことからデフォルトを変更する予定はないようです[3]

脚注
  1. https://qiita.com/mtsmfm/items/c967e0624bbafb25f2a3 ↩︎

  2. https://github.com/rails/rails/pull/17607#issuecomment-70538060 ↩︎

  3. https://github.com/sharpstone/rack-timeout/issues/169#issuecomment-806077437 ↩︎