Merge remote-tracking branch 'origin/master'

Author: graywh

.github/workflows/check_changelog.yml

@@ -0,0 +1,12 @@
+name: Check Changelog
+
+on: [pull_request]
+
+jobs:
+  build:
+    runs-on: ubuntu-latest
+    steps:
+    - uses: actions/checkout@v1
+    - name: Check that CHANGELOG is touched
+      run: |
+        cat $GITHUB_EVENT_PATH | jq .pull_request.title |  grep -i '\[\(\(changelog skip\)\|\(ci skip\)\)\]' ||  git diff remotes/origin/${{ github.base_ref }} --name-only | grep CHANGELOG.md

.github/workflows/ci.yml

@@ -0,0 +1,32 @@
+name: CI
+
+on:
+  - push
+  - pull_request
+
+jobs:
+  test:
+    runs-on: ubuntu-latest
+    strategy:
+      fail-fast: false
+      matrix:
+        ruby:
+          - '2.2'
+          - '2.3'
+          - '2.4'
+          - '2.5'
+          - '2.6'
+          - '2.7'
+          - '3.0'
+          - '3.1'
+          - 'head'
+    steps:
+      - name: Checkout code
+        uses: actions/checkout@v3
+      - name: Set up Ruby
+        uses: ruby/setup-ruby@v1
+        with:
+          ruby-version: ${{ matrix.ruby }}
+          bundler-cache: true
+      - name: Run test
+        run: bundle exec rake test

.travis.yml

@@ -1,3 +1,27 @@
+## HEAD (unreleased)
+
+## 0.6.3
+
+- Fix `NoMethodError: undefined method 'logger' for Rails:Module` when Rails is defined as a Module, but is not a full Rails app (https://github.com/zombocom/rack-timeout/pull/180)
+
+## 0.6.2
+
+- Migrate CI from Travis CI to GitHub Actions (https://github.com/zombocom/rack-timeout/pull/182)
+- Rails 7+ support (https://github.com/zombocom/rack-timeout/pull/184)
+
+## 0.6.1
+
+- RACK_TIMEOUT_TERM_ON_TIMEOUT can be set to zero to disable (https://github.com/sharpstone/rack-timeout/pull/161)
+- Update the gemspec's homepage to the current repo URL(https://github.com/zombocom/rack-timeout/pull/183)
+
+## 0.6.0
+
+- Allow sending SIGTERM to workers on timeout (https://github.com/sharpstone/rack-timeout/pull/157)
+
+0.5.2
+=====
+- Rails 6 support (#147)
+
 0.5.1
 =====
 - Fixes setting ENV vars to false or 0 would not disable a timeout

CHANGELOG.md

@@ -15,7 +15,7 @@ Pass an an array of paths strings you want to exclude from or only run timeout f
 
 ```ruby
 # Gemfile
-gem "rack-timeout", require:"rack/timeout/base", :git => 'git://github.com/mkrl/rack-timeout.git'
+gem "rack-timeout", require:"rack/timeout/base", :git => 'git://github.com/cqsdev/rack-timeout.git'
 ```
 
 ```ruby
@@ -40,6 +40,7 @@ service_timeout:   15     # RACK_TIMEOUT_SERVICE_TIMEOUT
 wait_timeout:      30     # RACK_TIMEOUT_WAIT_TIMEOUT
 wait_overtime:     60     # RACK_TIMEOUT_WAIT_OVERTIME
 service_past_wait: false  # RACK_TIMEOUT_SERVICE_PAST_WAIT
+term_on_timeout:   false  # RACK_TIMEOUT_TERM_ON_TIMEOUT
 exclude:           []     # RACK_TIMEOUT_EXCLUDE
 only:              []     # RACK_TIMEOUT_ONLY
 ```
@@ -58,5 +59,5 @@ use Rack::Timeout::Select, service_timeout: 5, exclude: ["api"]
 Please note that you may have controller actions with names similar to your excludes/targets, use with wise.
 
 ---
-Copyright © 2010-2016 Caio Chassot, released under the MIT license
-<http://github.com/heroku/rack-timeout>
+Copyright © 2010-2020 Caio Chassot, released under the MIT license
+<http://github.com/sharpstone/rack-timeout>

README.md

@@ -26,7 +26,6 @@ That said, it's something to be aware of, and may explain some eerie wonkiness s
 [broken-timeout]: http://headius.blogspot.de/2008/02/rubys-threadraise-threadkill-timeoutrb.html
 [handle-interrupt]: http://www.ruby-doc.org/core-2.1.3/Thread.html#method-c-handle_interrupt
 
-
 ### Time Out Early and Often
 
 Because of the aforementioned issues, it's recommended you set library-specific timeouts and leave Rack::Timeout as a last resort measure. Library timeouts will generally take care of IO issues and abort the operation safely. See [The Ultimate Guide to Ruby Timeouts][ruby-timeouts].

doc/risks.md

@@ -47,3 +47,55 @@ This extra time is called *wait overtime* and can be set via `wait_overtime`. It
 Keep in mind that Heroku [recommends][uploads] uploading large files directly to S3, so as to prevent the dyno from being blocked for too long and hence unable to handle further incoming requests.
 
 [uploads]: https://devcenter.heroku.com/articles/s3#file-uploads
+
+### Term on Timeout
+
+If your application timeouts fire frequently then [they can cause your application to enter a corrupt state](https://www.schneems.com/2017/02/21/the-oldest-bug-in-ruby-why-racktimeout-might-hose-your-server/). One option for resetting that bad state is to restart the entire process. If you are running in an environment with multiple processes (such as `puma -w 2`) then when a process is sent a `SIGTERM` it will exit. The webserver then knows how to restart the process. For more information on process restart behavior see:
+
+- [Ruby Application Restart Behavior](https://devcenter.heroku.com/articles/what-happens-to-ruby-apps-when-they-are-restarted)
+- [License to SIGKILL](https://www.sitepoint.com/license-to-sigkill/)
+
+**Puma SIGTERM behavior** When a Puma worker receives a `SIGTERM` it will begin to shut down, but not exit right away. It stops accepting new requests and waits for any existing requests to finish before fully shutting down. This means that only the request that experiences a timeout will be interupted, all other in-flight requests will be allowed to run until they return or also are timed out.
+
+After the worker process exists will Puma's parent process know to boot a replacement worker. While one process is restarting, another can still serve requests (if you have more than 1 worker process per server/dyno). Between when a process exits and when a new process boots, there will be a reduction in throughput. If all processes are restarting, then incoming requests will be blocked while new processes boot.
+
+**How to enable** To enable this behavior you can set `term_on_timeout: 1` to an integer value. If you set it to one, then the first time the process encounters a timeout, it will receive a SIGTERM.
+
+To enable on Heroku run:
+
+```
+$ heroku config:set RACK_TIMEOUT_TERM_ON_TIMEOUT=1
+```
+
+**Caution** If you use this setting inside of a webserver without enabling multi-process mode, then it will exit the entire server when it fires:
+
+- ✅ `puma -w 2 -t 5` This is OKAY
+- ❌ `puma -t 5` This is NOT OKAY
+
+If you're using a `config/puma.rb` file then make sure you are calling `workers` configuration DSL. You should see multiple workers when the server boots:
+
+```
+[3922] Puma starting in cluster mode...
+[3922] * Version 4.3.0 (ruby 2.6.5-p114), codename: Mysterious Traveller
+[3922] * Min threads: 0, max threads: 16
+[3922] * Environment: development
+[3922] * Process workers: 2
+[3922] * Phased restart available
+[3922] * Listening on tcp://0.0.0.0:9292
+[3922] Use Ctrl-C to stop
+[3922] - Worker 0 (pid: 3924) booted, phase: 0
+[3922] - Worker 1 (pid: 3925) booted, phase: 0
+```
+
+> ✅ Notice how it says it is booting in "cluster mode" and how it gives PIDs for two worker processes at the bottom.
+
+**How to decide the term_on_timeout value** If you set to a higher value such as `5` then rack-timeout will wait until the process has experienced five timeouts before restarting the process. Setting this value to a higher number means the application restarts processes less frequently, so throughput will be less impacted. If you set it to too high of a number, then the underlying issue of the application being put into a bad state will not be effectively mitigated.
+
+
+**How do I know when a process is being restarted by rack-timeout?** This exception error should be visible in the logs:
+
+```
+Request ran for longer than 1000ms, sending SIGTERM to process 3925
+```
+
+> Note: Since the worker waits for all in-flight requests to finish (with puma) you may see multiple SIGTERMs to the same PID before it exits, this means that multiple requests timed out.

doc/settings.md

@@ -1,2 +1,2 @@
 require_relative "rack/timeout/base"
-require_relative "rack/timeout/rails" if defined?(Rails) && [3,4,5].include?(Rails::VERSION::MAJOR)
+require_relative "rack/timeout/rails" if defined?(Rails) && Rails::VERSION::MAJOR >= 3

lib/rack-timeout.rb

@@ -30,6 +30,7 @@ class RequestTimeoutException < Exception # This is first raised to help prevent
       :service,   # time rack spent processing the request (updated ~ every second)
       :timeout,   # the actual computed timeout to be used for this request
       :state,     # the request's current state, see VALID_STATES below
+      :term,
     ) {
       def ms(k)   # helper method used for formatting values in milliseconds
         "%.fms" % (self[k] * 1000) if self[k]
@@ -86,16 +87,23 @@ def read_timeout_property value, default
       :wait_timeout,      # How long the request is allowed to have waited before reaching rack. If exceeded, the request is 'expired', i.e. dropped entirely without being passed down to the application.
       :wait_overtime,     # Additional time over @wait_timeout for requests with a body, like POST requests. These may take longer to be received by the server before being passed down to the application, but should not be expired.
       :service_past_wait  # when false, reduces the request's computed timeout from the service_timeout value if the complete request lifetime (wait + service) would have been longer than wait_timeout (+ wait_overtime when applicable). When true, always uses the service_timeout value. we default to false under the assumption that the router would drop a request that's not responded within wait_timeout, thus being there no point in servicing beyond seconds_service_left (see code further down) up until service_timeout.
+      :term_on_timeout
       :exclude            # exclude routes with those paths in them from being processed
       :only               # only process requests coming from those paths
 
-    def initialize(app, service_timeout:nil, wait_timeout:nil, wait_overtime:nil, service_past_wait:"not_specified", exclude:[], only:[])
+    def initialize(app, service_timeout:nil, wait_timeout:nil, wait_overtime:nil, service_past_wait:"not_specified", term_on_timeout: nil, exclude:[], only:[])
+      @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
       @exclude           = exclude == [] ?                        ENV.fetch("RACK_TIMEOUT_EXCLUDE", []) : exclude
       @only              = only == [] ?                           ENV.fetch("RACK_TIMEOUT_ONLY", []) : only
+
+      Thread.main['RACK_TIMEOUT_COUNT'] ||= 0
+      if @term_on_timeout
+        raise "Current Runtime does not support processes" unless ::Process.respond_to?(:fork)
+      end
       @app = app
     end
 
@@ -117,7 +125,9 @@ def call(env)
         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 overriden later)
-        info.wait, info.timeout = seconds_waited, final_wait_timeout       # updating the info properties; info.timeout will be the wait timeout at this point
+        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)}."
@@ -130,7 +140,7 @@ def call(env)
       # 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
@@ -143,7 +153,22 @@ def call(env)
 
       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
-        app_thread.raise(RequestTimeoutException.new(env), "Request #{"waited #{info.ms(:wait)}, then " if info.wait}ran for longer than #{info.ms(:timeout)}")
+
+        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'] += 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
@@ -218,6 +243,5 @@ def self.unregister_state_change_observer(id)
     def self.notify_state_change_observers(env)
       @state_change_observers.values.each { |observer| observer.call(env) }
     end
-
   end
 end

lib/rack/timeout/core.rb

@@ -35,5 +35,4 @@ def update(new_device, new_level)
     @level      = new_level  || ::Logger::INFO
     self.logger = ::Rack::Timeout::StateChangeLoggingObserver.mk_logger(device, level)
   end
-
 end