From 5868eeecb2fbc85f3e4fabf3d16f27d259491c0d Mon Sep 17 00:00:00 2001 From: Eric Wong Date: Thu, 26 Nov 2009 14:09:45 -0800 Subject: cleanup and refactor error handling Make sure app errors get logged correctly, and we no longer return a 500 response when a client EOFs the write end (but not the read end) of a connection. --- lib/rainbows.rb | 1 + lib/rainbows/base.rb | 12 ++++----- lib/rainbows/error.rb | 34 ++++++++++++++++++++++++ lib/rainbows/ev_core.rb | 14 ++-------- lib/rainbows/fiber_pool.rb | 2 +- lib/rainbows/fiber_spawn.rb | 2 +- lib/rainbows/rev_thread_spawn.rb | 35 +++++++++---------------- lib/rainbows/revactor.rb | 27 +++++-------------- lib/rainbows/thread_pool.rb | 4 +-- lib/rainbows/thread_spawn.rb | 4 +-- t/t0000-simple-http.sh | 13 +++++++++- t/t0001-unix-http.sh | 13 +++++++++- t/t0009-broken-app.sh | 56 ++++++++++++++++++++++++++++++++++++++++ t/t0009.ru | 13 ++++++++++ 14 files changed, 161 insertions(+), 69 deletions(-) create mode 100644 lib/rainbows/error.rb create mode 100644 t/t0009-broken-app.sh create mode 100644 t/t0009.ru diff --git a/lib/rainbows.rb b/lib/rainbows.rb index 93e9fd4..9d81a2e 100644 --- a/lib/rainbows.rb +++ b/lib/rainbows.rb @@ -1,5 +1,6 @@ # -*- encoding: binary -*- require 'unicorn' +require 'rainbows/error' module Rainbows diff --git a/lib/rainbows/base.rb b/lib/rainbows/base.rb index 9a653ff..4be37f4 100644 --- a/lib/rainbows/base.rb +++ b/lib/rainbows/base.rb @@ -10,10 +10,9 @@ module Rainbows include Rainbows::Const G = Rainbows::G - def listen_loop_error(e) - G.alive or return - logger.error "Unhandled listen loop exception #{e.inspect}." - logger.error e.backtrace.join("\n") + def handle_error(client, e) + msg = Error.response(e) and client.write_nonblock(msg) + rescue end def init_worker_process(worker) @@ -40,7 +39,7 @@ module Rainbows begin # loop while ! hp.headers(env, buf) - IO.select([client], nil, nil, G.kato) or return client.close + IO.select([client], nil, nil, G.kato) or return buf << client.readpartial(CHUNK_SIZE) end @@ -60,13 +59,14 @@ module Rainbows out = [ alive ? CONN_ALIVE : CONN_CLOSE ] if hp.headers? HttpResponse.write(client, response, out) end while alive and hp.reset.nil? and env.clear - client.close # if we get any error, try to write something back to the client # assuming we haven't closed the socket, but don't get hung up # if the socket is already closed or broken. We'll always ensure # the socket is closed at the end of this function rescue => e handle_error(client, e) + ensure + client.close end def join_threads(threads) diff --git a/lib/rainbows/error.rb b/lib/rainbows/error.rb new file mode 100644 index 0000000..89b1187 --- /dev/null +++ b/lib/rainbows/error.rb @@ -0,0 +1,34 @@ +# -*- encoding: binary -*- +module Rainbows + + class Error + class << self + + def app(e) + G.server.logger.error "app error: #{e.inspect}" + G.server.logger.error e.backtrace.join("\n") + rescue + end + + def listen_loop(e) + G.alive or return + G.server.logger.error "listen loop error: #{e.inspect}." + G.server.logger.error e.backtrace.join("\n") + rescue + end + + def response(e) + case e + when EOFError,Errno::ECONNRESET,Errno::EPIPE,Errno::EINVAL,Errno::EBADF + # swallow error if client shuts down one end or disconnects + when Unicorn::HttpParserError + Const::ERROR_400_RESPONSE # try to tell the client they're bad + else + app(e) + Const::ERROR_500_RESPONSE + end + end + + end + end +end diff --git a/lib/rainbows/ev_core.rb b/lib/rainbows/ev_core.rb index e0fb029..f61b33f 100644 --- a/lib/rainbows/ev_core.rb +++ b/lib/rainbows/ev_core.rb @@ -26,17 +26,7 @@ module Rainbows end def handle_error(e) - msg = case e - when EOFError,Errno::ECONNRESET,Errno::EPIPE,Errno::EINVAL,Errno::EBADF - ERROR_500_RESPONSE - when HttpParserError # try to tell the client they're bad - ERROR_400_RESPONSE - else - G.server.logger.error "Read error: #{e.inspect}" - G.server.logger.error e.backtrace.join("\n") - ERROR_500_RESPONSE - end - write(msg) + msg = Error.response(e) and write(msg) ensure quit end @@ -79,7 +69,7 @@ module Rainbows @input.close if File === @input end end - rescue Object => e + rescue => e handle_error(e) end diff --git a/lib/rainbows/fiber_pool.rb b/lib/rainbows/fiber_pool.rb index c647676..25f086e 100644 --- a/lib/rainbows/fiber_pool.rb +++ b/lib/rainbows/fiber_pool.rb @@ -38,7 +38,7 @@ module Rainbows fib.resume(Fiber::IO.new(io, fib)) end rescue => e - listen_loop_error(e) + Error.listen_loop(e) end while G.alive || G.cur > 0 end diff --git a/lib/rainbows/fiber_spawn.rb b/lib/rainbows/fiber_spawn.rb index 83b64de..da3db01 100644 --- a/lib/rainbows/fiber_spawn.rb +++ b/lib/rainbows/fiber_spawn.rb @@ -30,7 +30,7 @@ module Rainbows ::Fiber.new { process_client(fio.new(io, ::Fiber.current)) }.resume end rescue => e - listen_loop_error(e) + Error.listen_loop(e) end while G.alive || G.cur > 0 end diff --git a/lib/rainbows/rev_thread_spawn.rb b/lib/rainbows/rev_thread_spawn.rb index b6c5eca..f2ce822 100644 --- a/lib/rainbows/rev_thread_spawn.rb +++ b/lib/rainbows/rev_thread_spawn.rb @@ -9,7 +9,7 @@ module Rainbows # A combination of the Rev and ThreadSpawn models. This allows Ruby # Thread-based concurrency for application processing. It DOES NOT # expose a streamable "rack.input" for upload processing within the - # app. DevFdResponse may be used with this class to proxy + # app. DevFdResponse should be used with this class to proxy # asynchronous responses. All network I/O between the client and # server are handled by the main thread and outside of the core # application dispatch. @@ -60,17 +60,17 @@ module Rainbows end end - def app_error(e) - case e - when EOFError,Errno::ECONNRESET,Errno::EPIPE,Errno::EINVAL,Errno::EBADF - else - begin - G.server.logger.error "App error: #{e.inspect}" - G.server.logger.error e.backtrace.join("\n") - rescue - end + # fails-safe application dispatch, we absolutely cannot + # afford to fail or raise an exception (killing the thread) + # here because that could cause a deadlock and we'd leak FDs + def app_response + begin + @env[REMOTE_ADDR] = @remote_addr + APP.call(@env.update(RACK_DEFAULTS)) + rescue => e + Error.app(e) # we guarantee this does not raise + [ 500, {}, [] ] end - [ 500, {}, [] ] end def app_call @@ -78,18 +78,7 @@ module Rainbows disable @env[RACK_INPUT] = @input @input = nil # not sure why, @input seems to get closed otherwise... - Thread.new do - @env[REMOTE_ADDR] = @remote_addr - begin - response = begin - APP.call(@env.update(RACK_DEFAULTS)) - rescue => e - app_error(e) - end - ensure - MASTER << [ client, response ] - end - end + Thread.new { MASTER << [ client, app_response ] } end end diff --git a/lib/rainbows/revactor.rb b/lib/rainbows/revactor.rb index 489236c..4e4b381 100644 --- a/lib/rainbows/revactor.rb +++ b/lib/rainbows/revactor.rb @@ -63,11 +63,11 @@ module Rainbows out = [ alive ? CONN_ALIVE : CONN_CLOSE ] if hp.headers? HttpResponse.write(client, response, out) end while alive and hp.reset.nil? and env.clear - client.close rescue ::Revactor::TCP::ReadError - client.close rescue => e handle_error(client, e) + ensure + client.close end # runs inside each forked worker, this sits around and waits @@ -95,8 +95,8 @@ module Rainbows clients[actor.object_id] = actor root.link(actor) rescue Errno::EAGAIN, Errno::ECONNABORTED - rescue Object => e - listen_loop_error(e) + rescue => e + Error.listen_loop(e) end while G.alive end end @@ -119,23 +119,10 @@ module Rainbows # if the socket is already closed or broken. We'll always ensure # the socket is closed at the end of this function def handle_error(client, e) - msg = case e - when EOFError,Errno::ECONNRESET,Errno::EPIPE,Errno::EINVAL,Errno::EBADF - Const::ERROR_500_RESPONSE - when HttpParserError # try to tell the client they're bad - Const::ERROR_400_RESPONSE - else - logger.error "Read error: #{e.inspect}" - logger.error e.backtrace.join("\n") - Const::ERROR_500_RESPONSE - end - client.instance_eval do - # this is Revactor implementation dependent - @_io.write_nonblock(msg) - close - end + # this is Revactor implementation dependent + msg = Error.response(e) and + client.instance_eval { @_io.write_nonblock(msg) } rescue - nil end def revactorize_listeners! diff --git a/lib/rainbows/thread_pool.rb b/lib/rainbows/thread_pool.rb index 7934dc8..949db6f 100644 --- a/lib/rainbows/thread_pool.rb +++ b/lib/rainbows/thread_pool.rb @@ -59,8 +59,8 @@ module Rainbows rescue Errno::EBADF, TypeError break end - rescue Object => e - listen_loop_error(e) + rescue => e + Error.listen_loop(e) end while G.alive } end diff --git a/lib/rainbows/thread_spawn.rb b/lib/rainbows/thread_spawn.rb index a3068c9..73a4107 100644 --- a/lib/rainbows/thread_spawn.rb +++ b/lib/rainbows/thread_spawn.rb @@ -51,8 +51,8 @@ module Rainbows rescue Errno::EAGAIN, Errno::ECONNABORTED end end - rescue Object => e - listen_loop_error(e) + rescue => e + Error.listen_loop(e) end while true join_threads(threads.list) end diff --git a/t/t0000-simple-http.sh b/t/t0000-simple-http.sh index 173281b..6f4d738 100755 --- a/t/t0000-simple-http.sh +++ b/t/t0000-simple-http.sh @@ -1,6 +1,6 @@ #!/bin/sh . ./test-lib.sh -t_plan 24 "simple HTTP connection keepalive/pipelining tests for $model" +t_plan 25 "simple HTTP connection keepalive/pipelining tests for $model" t_begin "checking for config.ru for $model" && { tbase=simple-http_$model.ru @@ -21,6 +21,17 @@ t_begin "single request" && { curl -sSfv http://$listen/ } +t_begin "handles client EOF gracefully" && { + printf 'GET / HTTP/1.1\r\nHost: example.com\r\n\r\n' | \ + socat - TCP4:$listen > $tmp + dbgcat tmp + if grep 'HTTP.* 500' $tmp + then + die "500 error returned on client shutdown(SHUT_WR)" + fi + check_stderr +} + dbgcat r_err t_begin "two requests with keepalive" && { diff --git a/t/t0001-unix-http.sh b/t/t0001-unix-http.sh index 59f996a..e9bc919 100755 --- a/t/t0001-unix-http.sh +++ b/t/t0001-unix-http.sh @@ -1,6 +1,6 @@ #!/bin/sh . ./test-lib.sh -t_plan 18 "simple HTTP connection keepalive/pipelining tests for $model" +t_plan 19 "simple HTTP connection keepalive/pipelining tests for $model" t_begin "checking for config.ru for $model" && { tbase=simple-http_$model.ru @@ -23,6 +23,17 @@ t_begin "single TCP request" && { curl -sSfv http://$listen/ } +t_begin "handles client EOF gracefully" && { + printf 'GET / HTTP/1.1\r\nHost: example.com\r\n\r\n' | \ + socat - UNIX:$unix_socket > $tmp + dbgcat tmp + if grep 'HTTP.* 500' $tmp + then + die "500 error returned on client shutdown(SHUT_WR)" + fi + check_stderr +} + dbgcat r_err t_begin "pipelining partial requests" && { diff --git a/t/t0009-broken-app.sh b/t/t0009-broken-app.sh new file mode 100644 index 0000000..b5aae4e --- /dev/null +++ b/t/t0009-broken-app.sh @@ -0,0 +1,56 @@ +#!/bin/sh +. ./test-lib.sh + +t_plan 9 "graceful handling of broken apps for $model" + +t_begin "setup and start" && { + rainbows_setup + rainbows -D t0009.ru -c $unicorn_config $model 1 + rainbows_wait_start +} + +t_begin "normal response is alright" && { + test xOK = x"$(curl -sSf http://$listen/)" +} + +t_begin "app raised exception" && { + curl -sSf http://$listen/raise 2> $tmp || : + grep -F 500 $tmp + > $tmp +} + +t_begin "app exception logged and backtrace not swallowed" && { + grep -F 'app error' $r_err + grep -A1 -F 'app error' $r_err | tail -1 | grep t0009.ru: + dbgcat r_err + > $r_err +} + +t_begin "trigger bad response" && { + curl -sSf http://$listen/nil 2> $tmp || : + grep -F 500 $tmp + > $tmp +} + +t_begin "app exception logged" && { + grep -F 'app error' $r_err + > $r_err +} + +t_begin "normal responses alright afterwards" && { + > $tmp + curl -sSf http://$listen/ >> $tmp & + curl -sSf http://$listen/ >> $tmp & + curl -sSf http://$listen/ >> $tmp & + curl -sSf http://$listen/ >> $tmp & + wait + test xOK = x$(sort < $tmp | uniq) +} + +t_begin "teardown" && { + kill $rainbows_pid +} + +t_begin "check stderr" && check_stderr + +t_done diff --git a/t/t0009.ru b/t/t0009.ru new file mode 100644 index 0000000..bc7cb0b --- /dev/null +++ b/t/t0009.ru @@ -0,0 +1,13 @@ +#\-E none +# we do not want Rack::Lint or anything to protect us +use Rack::ContentLength +use Rack::ContentType, "text/plain" +map "/" do + run lambda { |env| [ 200, {}, [ "OK\n" ] ] } +end +map "/raise" do + run lambda { |env| raise "BAD" } +end +map "/nil" do + run lambda { |env| nil } +end -- cgit v1.2.3-24-ge0c7