Re: Combating nginx 499 HTTP responses during flash traffic scenario

[Tom Burns <tom.burns@jadedpixel.com>]

On Mon, Nov 5, 2012 at 6:48 AM, Eric Wong <normalperson@yhbt.net> wrote:
> We can wait until you can report on how this change improves your
> situation before fleshing this out.  Real-world results are always
> good to have :>
Agreed.

We're going to be testing this this week so I should have some results
to share by the weekend.  We only experience the problem during major
sales so it may or may not manifest without our traffic generation
tool.

I'd like to be testing a patch close to the finished product so I've
addressed all of your comments from the previous email (including the
modification to the C extension) in the patch below.

>
> Random thought:  HttpResponse generation gains even more coupling
> with the current Http{Request,Parser} state.  Organizing code is hard :x
Agreed.  Without a class wrapping the raw socket to hold state I
didn't see a better way to accomplish this, but I've only been looking
at this code for the past week or so.

Cheers,
Tom

---
>From c696bc0cb4df223a096142b6f314c8c2d83255be Mon Sep 17 00:00:00 2001
From: Tom Burns <tom.burns@jadedpixel.com>
Date: Tue, 30 Oct 2012 16:22:21 -0400
Subject: [PATCH] Begin writing HTTP request headers early to detect
 disconnected clients

This patch checks incoming connections and avoids calling the application
if the connection has been closed.

It works by sending the beginning of the HTTP response before calling
the application to see if the socket can successfully be written to.

By enabling this feature users can avoid wasting application rendering
time only to find the connection is closed when attempting to write, and
throwing out the result.

When a client disconnects while being queued or processed, Nginx will log
HTTP response 499 but the application will log a 200.

Enabling this feature will minimize the time window during which the problem
can arise.

The feature is disabled by default and can be enabled by adding
'check_client_connection true' to the unicorn config.
---
 examples/unicorn.conf.rb         |    6 ++++++
 ext/unicorn_http/unicorn_http.rl |    4 +++-
 lib/unicorn/configurator.rb      |   14 ++++++++++++++
 lib/unicorn/const.rb             |   12 ++++++++----
 lib/unicorn/http_request.rb      |   19 +++++++++++++++++++
 lib/unicorn/http_response.rb     |    5 +++--
 lib/unicorn/http_server.rb       |   22 ++++++++++++++++++++--
 test/exec/test_exec.rb           |    7 ++++++-
 test/unit/test_configurator.rb   |   24 ++++++++++++++++++++++++
 9 files changed, 103 insertions(+), 10 deletions(-)

diff --git a/examples/unicorn.conf.rb b/examples/unicorn.conf.rb
index 0238043..1f4c9c0 100644
--- a/examples/unicorn.conf.rb
+++ b/examples/unicorn.conf.rb
@@ -46,6 +46,12 @@ preload_app true
 GC.respond_to?(:copy_on_write_friendly=) and
   GC.copy_on_write_friendly = true

+# Enable this flag to have unicorn test client connections by writing the
+# beginning of the HTTP headers before calling the application.  This
+# prevents calling the application for connections that have disconnected
+# while queued.
+check_client_connection false
+
 before_fork do |server, worker|
   # the following is highly recomended for Rails + "preload_app true"
   # as there's no need for the master process to hold a connection
diff --git a/ext/unicorn_http/unicorn_http.rl b/ext/unicorn_http/unicorn_http.rl
index 96dcf83..52f7f3c 100644
--- a/ext/unicorn_http/unicorn_http.rl
+++ b/ext/unicorn_http/unicorn_http.rl
@@ -115,7 +115,7 @@ struct http_parser {
   } len;
 };

-static ID id_clear, id_set_backtrace;
+static ID id_clear, id_set_backtrace, id_response_start_sent;

 static void finalize_header(struct http_parser *hp);

@@ -626,6 +626,7 @@ static VALUE HttpParser_clear(VALUE self)

   http_parser_init(hp);
   rb_funcall(hp->env, id_clear, 0);
+  rb_funcall(self, id_response_start_sent, 1, Qfalse);

   return self;
 }
@@ -1031,6 +1032,7 @@ void Init_unicorn_http(void)
   SET_GLOBAL(g_http_connection, "CONNECTION");
   id_clear = rb_intern("clear");
   id_set_backtrace = rb_intern("set_backtrace");
+  id_response_start_sent = rb_intern("response_start_sent=");
   init_unicorn_httpdate();
 }
 #undef SET_GLOBAL
diff --git a/lib/unicorn/configurator.rb b/lib/unicorn/configurator.rb
index 89cbf5c..5f329af 100644
--- a/lib/unicorn/configurator.rb
+++ b/lib/unicorn/configurator.rb
@@ -45,6 +45,7 @@ class Unicorn::Configurator
       },
     :pid => nil,
     :preload_app => false,
+    :check_client_connection => false,
     :rewindable_input => true, # for Rack 2.x: (Rack::VERSION[0] <= 1),
     :client_body_buffer_size => Unicorn::Const::MAX_BODY,
     :trust_x_forwarded => true,
@@ -96,6 +97,13 @@ class Unicorn::Configurator
     if ready_pipe = RACKUP.delete(:ready_pipe)
       server.ready_pipe = ready_pipe
     end
+    if set[:check_client_connection]
+      set[:listeners].each do |address|
+        if set[:listener_opts][address][:tcp_nopush] == true ||
set[:listener_opts][address][:tcp_nodelay] == true
+          raise ArgumentError, "With check_client_connection set to
true both :tcp_nopush and :tcp_nodelay listener options must be set to
false."
+        end
+      end
+    end
     set.each do |key, value|
       value == :unset and next
       skip.include?(key) and next
@@ -454,6 +462,12 @@ class Unicorn::Configurator
     set_int(:client_body_buffer_size, bytes, 0)
   end

+  # When enabled, unicorn will check the client connection by writing
+  # the beginning of the HTTP headers before calling the application.
+  def check_client_connection(bool)
+    set_bool(:check_client_connection, bool)
+  end
+
   # Allow redirecting $stderr to a given path.  Unlike doing this from
   # the shell, this allows the unicorn process to know the path its
   # writing to and rotate the file if it is used for logging.  The
diff --git a/lib/unicorn/const.rb b/lib/unicorn/const.rb
index b3d8d71..f0c4c12 100644
--- a/lib/unicorn/const.rb
+++ b/lib/unicorn/const.rb
@@ -29,12 +29,16 @@ module Unicorn::Const

   # :stopdoc:
   # common errors we'll send back
-  ERROR_400_RESPONSE = "HTTP/1.1 400 Bad Request\r\n\r\n"
-  ERROR_414_RESPONSE = "HTTP/1.1 414 Request-URI Too Long\r\n\r\n"
-  ERROR_413_RESPONSE = "HTTP/1.1 413 Request Entity Too Large\r\n\r\n"
-  ERROR_500_RESPONSE = "HTTP/1.1 500 Internal Server Error\r\n\r\n"
+  ERROR_400_RESPONSE = "400 Bad Request\r\n\r\n"
+  ERROR_414_RESPONSE = "414 Request-URI Too Long\r\n\r\n"
+  ERROR_413_RESPONSE = "413 Request Entity Too Large\r\n\r\n"
+  ERROR_500_RESPONSE = "500 Internal Server Error\r\n\r\n"
+
   EXPECT_100_RESPONSE = "HTTP/1.1 100 Continue\r\n\r\n"
+  EXPECT_100_RESPONSE_SUFFIXED = "100 Continue\r\n\r\nHTTP/1.1 "

+  HTTP_RESPONSE_START = ['HTTP', '/1.1 ']
   HTTP_EXPECT = "HTTP_EXPECT"
+
   # :startdoc:
 end
diff --git a/lib/unicorn/http_request.rb b/lib/unicorn/http_request.rb
index a0435d6..79ead2e 100644
--- a/lib/unicorn/http_request.rb
+++ b/lib/unicorn/http_request.rb
@@ -22,11 +22,14 @@ class Unicorn::HttpParser

   NULL_IO = StringIO.new("")

+  attr_accessor :response_start_sent
+
   # :stopdoc:
   # A frozen format for this is about 15% faster
   REMOTE_ADDR = 'REMOTE_ADDR'.freeze
   RACK_INPUT = 'rack.input'.freeze
   @@input_class = Unicorn::TeeInput
+  @@check_client_connection = false

   def self.input_class
     @@input_class
@@ -35,6 +38,15 @@ class Unicorn::HttpParser
   def self.input_class=(klass)
     @@input_class = klass
   end
+
+  def self.check_client_connection
+    @@check_client_connection
+  end
+
+  def self.check_client_connection=(bool)
+    @@check_client_connection = bool
+  end
+
   # :startdoc:

   # Does the majority of the IO processing.  It has been written in
@@ -70,6 +82,13 @@ class Unicorn::HttpParser
       # an Exception thrown from the parser will throw us out of the loop
       false until add_parse(socket.kgio_read!(16384))
     end
+
+    # detect if the socket is valid by writing a partial response:
+    if @@check_client_connection && headers?
+      @response_start_sent = true
+      Unicorn::Const::HTTP_RESPONSE_START.each { |c| socket.write(c) }
+    end
+
     e[RACK_INPUT] = 0 == content_length ?
                     NULL_IO : @@input_class.new(socket, self)
     e.merge!(DEFAULTS)
diff --git a/lib/unicorn/http_response.rb b/lib/unicorn/http_response.rb
index b781e20..9c2bacc 100644
--- a/lib/unicorn/http_response.rb
+++ b/lib/unicorn/http_response.rb
@@ -18,11 +18,12 @@ module Unicorn::HttpResponse
   CRLF = "\r\n"

   # writes the rack_response to socket as an HTTP response
-  def http_response_write(socket, status, headers, body)
+  def http_response_write(socket, status, headers, body,
response_start_sent=false)
     status = CODES[status.to_i] || status

+    http_response_start = response_start_sent ? '' : 'HTTP/1.1 '
     if headers
-      buf = "HTTP/1.1 #{status}\r\n" \
+      buf = "#{http_response_start}#{status}\r\n" \
             "Date: #{httpdate}\r\n" \
             "Status: #{status}\r\n" \
             "Connection: close\r\n"
diff --git a/lib/unicorn/http_server.rb b/lib/unicorn/http_server.rb
index 13df55a..8729830 100644
--- a/lib/unicorn/http_server.rb
+++ b/lib/unicorn/http_server.rb
@@ -17,6 +17,7 @@ class Unicorn::HttpServer
                 :listener_opts, :preload_app,
                 :reexec_pid, :orig_app, :init_listeners,
                 :master_pid, :config, :ready_pipe, :user
+
   attr_reader :pid, :logger
   include Unicorn::SocketHelper
   include Unicorn::HttpResponse
@@ -355,6 +356,14 @@ class Unicorn::HttpServer
     Unicorn::HttpParser.trust_x_forwarded = bool
   end

+  def check_client_connection
+    Unicorn::HttpRequest.check_client_connection
+  end
+
+  def check_client_connection=(bool)
+    Unicorn::HttpRequest.check_client_connection = bool
+  end
+
   private

   # wait for a signal hander to wake us up and then consume the pipe
@@ -524,23 +533,32 @@ class Unicorn::HttpServer
       Unicorn.log_error(@logger, "app error", e)
       Unicorn::Const::ERROR_500_RESPONSE
     end
+    msg = "HTTP/1.1 #{msg}" unless @request.response_start_sent
     client.kgio_trywrite(msg)
     client.close
     rescue
   end

+  def expect_100_response
+    if @request.response_start_sent
+      Unicorn::Const::EXPECT_100_RESPONSE_SUFFIXED
+    else
+      Unicorn::Const::EXPECT_100_RESPONSE
+    end
+  end
+
   # once a client is accepted, it is processed in its entirety here
   # in 3 easy steps: read request, call app, write app response
   def process_client(client)
     status, headers, body = @app.call(env = @request.read(client))

     if 100 == status.to_i
-      client.write(Unicorn::Const::EXPECT_100_RESPONSE)
+      client.write(expect_100_response)
       env.delete(Unicorn::Const::HTTP_EXPECT)
       status, headers, body = @app.call(env)
     end
     @request.headers? or headers = nil
-    http_response_write(client, status, headers, body)
+    http_response_write(client, status, headers, body,
@request.response_start_sent)
     client.shutdown # in case of fork() in Rack app
     client.close # flush and uncork socket immediately, no keepalive
   rescue => e
diff --git a/test/exec/test_exec.rb b/test/exec/test_exec.rb
index b30a3d6..1cee2b7 100644
--- a/test/exec/test_exec.rb
+++ b/test/exec/test_exec.rb
@@ -871,13 +871,14 @@ EOF
     wait_for_death(pid)
   end

-  def hup_test_common(preload)
+  def hup_test_common(preload, check_client=false)
     File.open("config.ru", "wb") { |fp| fp.syswrite(HI.gsub("HI", '#$$')) }
     pid_file = Tempfile.new('pid')
     ucfg = Tempfile.new('unicorn_test_config')
     ucfg.syswrite("listen '#@addr:#@port'\n")
     ucfg.syswrite("pid '#{pid_file.path}'\n")
     ucfg.syswrite("preload_app true\n") if preload
+    ucfg.syswrite("check_client_connection true\n") if check_client
     ucfg.syswrite("stderr_path 'test_stderr.#$$.log'\n")
     ucfg.syswrite("stdout_path 'test_stdout.#$$.log'\n")
     pid = xfork {
@@ -942,6 +943,10 @@ EOF
     hup_test_common(false)
   end

+  def test_check_client_hup
+    hup_test_common(false, true)
+  end
+
   def test_default_listen_hup_holds_listener
     default_listen_lock do
       res, pid_path = default_listen_setup
diff --git a/test/unit/test_configurator.rb b/test/unit/test_configurator.rb
index c19c427..b9c22d7 100644
--- a/test/unit/test_configurator.rb
+++ b/test/unit/test_configurator.rb
@@ -139,6 +139,30 @@ class TestConfigurator < Test::Unit::TestCase
     end
   end

+  def test_check_client_connection
+    tmp = Tempfile.new('unicorn_config')
+    test_struct = TestStruct.new
+    tmp.syswrite("check_client_connection true\n")
+
+    assert_nothing_raised do
+      Unicorn::Configurator.new(:config_file => tmp.path).commit!(test_struct)
+    end
+
+    assert test_struct.check_client_connection
+  end
+
+  def test_check_client_connection_with_tcp_bad
+    tmp = Tempfile.new('unicorn_config')
+    test_struct = TestStruct.new
+    listener = "127.0.0.1:12345"
+    tmp.syswrite("check_client_connection true\n")
+    tmp.syswrite("listen '#{listener}', :tcp_nopush => true\n")
+
+    assert_raises(ArgumentError) do
+      Unicorn::Configurator.new(:config_file => tmp.path).commit!(test_struct)
+    end
+  end
+
   def test_after_fork_proc
     test_struct = TestStruct.new
     [ proc { |a,b| }, Proc.new { |a,b| }, lambda { |a,b| } ].each do |my_proc|
-- 
1.7.7.5 (Apple Git-26)
_______________________________________________
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying