Add between_bytes_timeout to fix timing out when we get a slow request

History.md

@@ -4,6 +4,7 @@
   * Your feature goes here <Most recent on the top, like GitHub> (#Github Number)
   * Warn when running Cluster mode with a single worker (#2565)
   * Add reason to worker time out and startup time when worked boots ([#2528])
+  * Add :between_bytes_timeout to prevent timeout during slow incoming requests (#2575)
 
 * Bugfixes
   * Your bugfix goes here <Most recent on the top, like GitHub> (#Github Number)

lib/puma/client.rb

@@ -205,8 +205,9 @@ def eagerly_finish
       try_to_finish
     end
 
-    def finish(timeout)
+    def finish(first_data_timeout, between_bytes_timeout)
       return if @ready
+      timeout = @parsed_bytes > 0 ? between_bytes_timeout : first_data_timeout
       IO.select([@to_io], nil, nil, timeout) || timeout! until try_to_finish
     end
 

lib/puma/dsl.rb

@@ -272,6 +272,12 @@ def first_data_timeout(seconds)
       @options[:first_data_timeout] = Integer(seconds)
     end
 
+    # Define how long the tcp socket stays open, once data has been received.
+    # @see Puma::Server.new
+    def between_bytes_timeout(seconds)
+      @options[:between_bytes_timeout] = Integer(seconds)
+    end
+
     # Work around leaky apps that leave garbage in Thread locals
     # across requests.
     def clean_thread_locals(which=true)

lib/puma/server.rb

@@ -40,12 +40,14 @@ class Server
     attr_reader :requests_count             # @version 5.0.0
 
     # @todo the following may be deprecated in the future
-    attr_reader :auto_trim_time, :early_hints, :first_data_timeout,
+    attr_reader :auto_trim_time, :early_hints,
+      :first_data_timeout, :between_bytes_timeout,
       :leak_stack_on_error,
       :persistent_timeout, :reaping_time
 
     # @deprecated v6.0.0
-    attr_writer :auto_trim_time, :early_hints, :first_data_timeout,
+    attr_writer :auto_trim_time, :early_hints,
+      :first_data_timeout, :between_bytes_timeout,
       :leak_stack_on_error, :min_threads, :max_threads,
       :persistent_timeout, :reaping_time
 
@@ -84,14 +86,15 @@ def initialize(app, events=Events.stdio, options={})
 
       @options = options
 
-      @early_hints         = options.fetch :early_hints, nil
-      @first_data_timeout  = options.fetch :first_data_timeout, FIRST_DATA_TIMEOUT
-      @min_threads         = options.fetch :min_threads, 0
-      @max_threads         = options.fetch :max_threads , (Puma.mri? ? 5 : 16)
-      @persistent_timeout  = options.fetch :persistent_timeout, PERSISTENT_TIMEOUT
-      @queue_requests      = options.fetch :queue_requests, true
-      @max_fast_inline     = options.fetch :max_fast_inline, MAX_FAST_INLINE
-      @io_selector_backend = options.fetch :io_selector_backend, :auto
+      @early_hints           = options.fetch :early_hints, nil
+      @first_data_timeout    = options.fetch :first_data_timeout, FIRST_DATA_TIMEOUT
+      @between_bytes_timeout = options.fetch :between_bytes_timeout, @first_data_timeout
+      @min_threads           = options.fetch :min_threads, 0
+      @max_threads           = options.fetch :max_threads , (Puma.mri? ? 5 : 16)
+      @persistent_timeout    = options.fetch :persistent_timeout, PERSISTENT_TIMEOUT
+      @queue_requests        = options.fetch :queue_requests, true
+      @max_fast_inline       = options.fetch :max_fast_inline, MAX_FAST_INLINE
+      @io_selector_backend   = options.fetch :io_selector_backend, :auto
 
       temp = !!(@options[:environment] =~ /\A(development|test)\z/)
       @leak_stack_on_error = @options[:environment] ? temp : true
@@ -295,6 +298,9 @@ def reactor_wakeup(client)
         @thread_pool << client
       elsif shutdown || client.timeout == 0
         client.timeout!
+      else
+        client.set_timeout(@between_bytes_timeout)
+        false
       end
     rescue StandardError => e
       client_error(e, client)
@@ -423,7 +429,7 @@ def process_client(client, buffer)
         end
 
         with_force_shutdown(client) do
-          client.finish(@first_data_timeout)
+          client.finish(@first_data_timeout, @between_bytes_timeout)
         end
 
         while true

test/test_puma_server.rb

@@ -382,13 +382,21 @@ def test_status_hook_fires_when_server_changes_states
     assert_equal [:booting, :running, :stop, :done], states
   end
 
+  def assert_proper_timeout(expected)
+    now = Time.now
+    ret = yield
+    t = Time.now - now
+    assert_in_delta expected, t, 0.5, "unexpected timeout, #{t} instead of ~#{expected}"
+    ret
+  end
+
   def test_timeout_in_data_phase
     @server.first_data_timeout = 2
     server_run
 
     sock = send_http "POST / HTTP/1.1\r\nHost: test.com\r\nContent-Type: text/plain\r\nContent-Length: 5\r\n\r\n"
 
-    data = sock.gets
+    data = assert_proper_timeout(@server.first_data_timeout) { sock.gets }
 
     assert_equal "HTTP/1.1 408 Request Timeout\r\n", data
   end
@@ -398,6 +406,49 @@ def test_timeout_data_no_queue
     test_timeout_in_data_phase
   end
 
+  def test_timeout_after_data_received
+    @server.first_data_timeout = 4
+    @server.between_bytes_timeout = 2
+    server_run
+
+    sock = send_http "POST / HTTP/1.1\r\nHost: test.com\r\nContent-Type: text/plain\r\nContent-Length: 100\r\n\r\n"
+    sleep 0.1
+
+    sock << "hello"
+    sleep 0.1
+
+    data = assert_proper_timeout(@server.between_bytes_timeout) { sock.gets }
+
+    assert_equal "HTTP/1.1 408 Request Timeout\r\n", data
+  end
+
+  def test_timeout_after_data_received_no_queue
+    @server = Puma::Server.new @app, @events, queue_requests: false
+    test_timeout_after_data_received
+  end
+
+  def test_no_timeout_after_data_received
+    @server.first_data_timeout = 10
+    @server.between_bytes_timeout = 4
+    server_run
+
+    sock = send_http "POST / HTTP/1.1\r\nHost: test.com\r\nContent-Type: text/plain\r\nContent-Length: 10\r\n\r\n"
+    sleep 0.1
+
+    sock << "hello"
+    sleep 2
+    sock << "world"
+
+    data = sock.gets
+
+    assert_equal "HTTP/1.1 200 OK\r\n", data
+  end
+
+  def test_no_timeout_after_data_received_no_queue
+    @server = Puma::Server.new @app, @events, queue_requests: false
+    test_no_timeout_after_data_received
+  end
+
   def test_http_11_keep_alive_with_body
     server_run app: ->(env) { [200, {"Content-Type" => "plain/text"}, ["hello\n"]] }