class Rack::Timeout
Constants
- ACTION_DISPATCH_REQUEST_ID
- ENV_INFO_KEY
- HTTP_X_REQUEST_ID
- HTTP_X_REQUEST_START
- RT
- RX_APACHE_X_REQUEST_START
- RX_HEROKU_X_REQUEST_START
- RX_NGINX_X_REQUEST_START
X-Request-Start contains the time the request was first seen by the server. Format varies wildly amongst servers, yay!
- nginx gives the time since epoch as seconds.milliseconds[1]. New Relic documentation recommends preceding it with t=[2], so might as well detect it. - Heroku gives the time since epoch in milliseconds. [3] - Apache uses t=microseconds[4], so 16 digits (until November 2286).
The sane way to handle this would be by knowing the server being used, instead let’s just hack around with regular expressions. [1]: nginx.org/en/docs/http/ngx_http_log_module.html#var_msec [2]: docs.newrelic.com/docs/apm/other-features/request-queueing/request-queue-server-configuration-examples#nginx [3]: devcenter.heroku.com/articles/http-routing#heroku-headers [4]: httpd.apache.org/docs/current/mod/mod_headers.html#header
This is a code extraction for readability, this method is only called from a single point.
- RequestDetails
- VALID_STATES
Attributes
Public Class Methods
# File lib/rack/timeout/core.rb, line 183 def self._read_x_request_start(env) return unless s = env[HTTP_X_REQUEST_START] if m = s.match(RX_HEROKU_X_REQUEST_START) || s.match(RX_NGINX_X_REQUEST_START) Time.at(m[1,2].join.to_f / 1000) elsif m = s.match(RX_APACHE_X_REQUEST_START) Time.at(m[1].to_f / 1_000_000) end end
This method determines if a body is present. requests with a body (generally POST, PUT) can have a lengthy body which may have taken a while to be received by the web server, inflating their computed wait time. This in turn could lead to unwanted expirations. See wait_overtime
property as a way to overcome those. This is a code extraction for readability, this method is only called from a single point.
# File lib/rack/timeout/core.rb, line 194 def self._request_has_body?(env) return true if env["HTTP_TRANSFER_ENCODING"] == "chunked" return false if env["CONTENT_LENGTH"].nil? return false if env["CONTENT_LENGTH"].to_i.zero? true end
# File lib/rack/timeout/core.rb, line 201 def self._set_state!(env, state) raise "Invalid state: #{state.inspect}" unless VALID_STATES.include? state env[ENV_INFO_KEY].state = state notify_state_change_observers(env) end
# File lib/rack/timeout/core.rb, line 69 def initialize(app, service_timeout:nil, wait_timeout:nil, wait_overtime:nil, service_past_wait:"not_specified", term_on_timeout: nil) @term_on_timeout = read_timeout_property term_on_timeout, ENV.fetch("RACK_TIMEOUT_TERM_ON_TIMEOUT", 0).to_i @service_timeout = read_timeout_property service_timeout, ENV.fetch("RACK_TIMEOUT_SERVICE_TIMEOUT", 15).to_i @wait_timeout = read_timeout_property wait_timeout, ENV.fetch("RACK_TIMEOUT_WAIT_TIMEOUT", 30).to_i @wait_overtime = read_timeout_property wait_overtime, ENV.fetch("RACK_TIMEOUT_WAIT_OVERTIME", 60).to_i @service_past_wait = service_past_wait == "not_specified" ? ENV.fetch("RACK_TIMEOUT_SERVICE_PAST_WAIT", false).to_s != "false" : service_past_wait if @term_on_timeout && !::Process.respond_to?(:fork) raise(NotImplementedError, <<-MSG) The platform running your application does not support forking (i.e. Windows, JVM, etc). To avoid this error, either specify RACK_TIMEOUT_TERM_ON_TIMEOUT=0 or leave it as default (which will have the same result). MSG end @app = app end
Registers a block to be called back when a request changes state in rack-timeout. The block will receive the request’s env.
‘id` is anything that uniquely identifies this particular callback, mostly so it may be removed via `unregister_state_change_observer`.
# File lib/rack/timeout/core.rb, line 213 def self.register_state_change_observer(id, &callback) raise RuntimeError, "An observer with the id #{id.inspect} is already set." if @state_change_observers.key? id raise ArgumentError, "A callback block is required." unless callback @state_change_observers[id] = callback end
Removes the observer with the given id
# File lib/rack/timeout/core.rb, line 220 def self.unregister_state_change_observer(id) @state_change_observers.delete(id) end
Private Class Methods
Sends out the notifications. Called internally at the end of ‘_set_state!`
# File lib/rack/timeout/core.rb, line 226 def self.notify_state_change_observers(env) @state_change_observers.values.each { |observer| observer.call(env) } end
Public Instance Methods
# File lib/rack/timeout/core.rb, line 90 def call(env) info = (env[ENV_INFO_KEY] ||= RequestDetails.new) info.id ||= env[HTTP_X_REQUEST_ID] || env[ACTION_DISPATCH_REQUEST_ID] || SecureRandom.uuid time_started_service = Time.now # The wall time the request started being processed by rack ts_started_service = fsecs # The monotonic time the request started being processed by rack time_started_wait = RT._read_x_request_start(env) # The time the request was initially received by the web server (if available) effective_overtime = (wait_overtime && RT._request_has_body?(env)) ? wait_overtime : 0 # additional wait timeout (if set and applicable) seconds_service_left = nil # if X-Request-Start is present and wait_timeout is set, expire requests older than wait_timeout (+wait_overtime when applicable) if time_started_wait && wait_timeout seconds_waited = time_started_service - time_started_wait # how long it took between the web server first receiving the request and rack being able to handle it seconds_waited = 0 if seconds_waited < 0 # make up for potential time drift between the routing server and the application server final_wait_timeout = wait_timeout + effective_overtime # how long the request will be allowed to have waited seconds_service_left = final_wait_timeout - seconds_waited # first calculation of service timeout (relevant if request doesn't get expired, may be overridden later) info.wait = seconds_waited # updating the info properties; info.timeout will be the wait timeout at this point info.timeout = final_wait_timeout if seconds_service_left <= 0 # expire requests that have waited for too long in the queue (as they are assumed to have been dropped by the web server / routing layer at this point) RT._set_state! env, :expired raise RequestExpiryError.new(env), "Request older than #{info.ms(:timeout)}." end end # pass request through if service_timeout is false (i.e., don't time it out at all.) return @app.call(env) unless service_timeout # compute actual timeout to be used for this request; if service_past_wait is true, this is just service_timeout. If false (the default), and wait time was determined, we'll use the shortest value between seconds_service_left and service_timeout. See comment above at service_past_wait for justification. info.timeout = service_timeout # nice and simple, when service_past_wait is true, not so much otherwise: info.timeout = seconds_service_left if !service_past_wait && seconds_service_left && seconds_service_left > 0 && seconds_service_left < service_timeout info.term = term_on_timeout RT._set_state! env, :ready # we're good to go, but have done nothing yet heartbeat_event = nil # init var so it's in scope for following proc register_state_change = ->(status = :active) { # updates service time and state; will run every second heartbeat_event.cancel! if status != :active # if the request is no longer active we should stop updating every second info.service = fsecs - ts_started_service # update service time RT._set_state! env, status # update status } heartbeat_event = RT::Scheduler.run_every(1) { register_state_change.call :active } # start updating every second while active; if log level is debug, this will log every sec timeout = RT::Scheduler::Timeout.new do |app_thread| # creates a timeout instance responsible for timing out the request. the given block runs if timed out register_state_change.call :timed_out message = +"Request " message << "waited #{info.ms(:wait)}, then " if info.wait message << "ran for longer than #{info.ms(:timeout)} " if term_on_timeout Thread.main['RACK_TIMEOUT_COUNT'] ||= 0 Thread.main['RACK_TIMEOUT_COUNT'] += 1 if Thread.main['RACK_TIMEOUT_COUNT'] >= term_on_timeout message << ", sending SIGTERM to process #{Process.pid}" Process.kill("SIGTERM", Process.pid) else message << ", #{Thread.main['RACK_TIMEOUT_COUNT']}/#{term_on_timeout} timeouts allowed before SIGTERM for process #{Process.pid}" end end app_thread.raise(RequestTimeoutException.new(env), message) end response = timeout.timeout(info.timeout) do # perform request with timeout begin @app.call(env) # boom, send request down the middleware chain rescue RequestTimeoutException => e # will actually hardly ever get to this point because frameworks tend to catch this. see README for more raise RequestTimeoutError.new(env), e.message, e.backtrace # but in case it does get here, re-raise RequestTimeoutException as RequestTimeoutError ensure register_state_change.call :completed end end response end
helper methods to read timeout properties. Ensure they’re always positive numbers or false. When set to false (or 0), their behaviour is disabled.
# File lib/rack/timeout/core.rb, line 51 def read_timeout_property value, default case value when nil ; read_timeout_property default, default when false ; false when 0 ; false else value.is_a?(Numeric) && value > 0 or raise ArgumentError, "value #{value.inspect} should be false, zero, or a positive number." value end end