rack-timeout を使用しておりパスごとにタイムアウトの指定を変更するため以前(rails 5.2.3、 rack-timeout 0.5.1 まで)は以下のように指定していました(多少簡略化してあります)。
gem 'rack-timeout', require: 'rack/timeout/base'
module Rack
class DynamicTimeout < Rack::Timeout
def call(env)
# URL が /admin から始まる場合は 30 秒、それ以外は 10 秒となるように
@service_timeout = env['REQUEST_URI'].start_with?('/admin') ? 30 : 10
super(env)
end
end
end
timeout_params = {
service_timeout: 10,
wait_timeout: 5.minutes.to_i,
wait_overtime: 5.minutes.to_i,
service_past_wait: false,
}
Rails.application.config.middleware.insert_before Rack::Runtime, Rack::DynamicTimeout, timeout_params
ところが Rails 6、あるいは rack-timeout 0.6.0 からタイムアウトが動的に指定した service_timeout
の値よりも短くなっていました。
以下のようにログに出力されている値(30秒)よりも実際は短かった(10秒)です。
severity:ERROR message:source=rack-timeout id=0284947e-c24c-4024-a9ba-c542b3eb58f9 timeout=30000ms service=10000ms state=timed_out
色々ログを仕込んだりして原因を調べたところ、どうやら Rack::DynamicTimeout
の call
とは別に Rack::Timeout
自体の call
が呼ばれているようでした。
都合2回 call
メソッドが実行されて最初は Rack::DynamicTimeout
で次が Rack::Timeout
になっており、最終的にタイムアウトの値は Rack::Timeout
で指定された値が使われるという状態です。
どこで呼ばれているか、それを変更できるかというところまで調べていくとちょっと時間がかかりそうだったので、今回は Rack::Timeout
を上書きするパッチで対応することにしました。
gem 'rack-timeout'
module Rack
module DynamicTimeout
def call(env)
# URL が /admin から始まる場合は 30 秒、それ以外は 10 秒となるように
@service_timeout = env['REQUEST_URI'].start_with?('/admin') ? 30 : 10
super(env)
end
end
end
Rack::Timeout.prepend Rack::DynamicTimeout
Module#prepend
でモジュールを差し込んで Rack::Timeout
の call
が呼ばれても対応できるようにしました。
ひとまずこれで。