kotovalexarian-likes-github/puma--puma
1
0
Fork 0
mirror of https://github.com/puma/puma.git synced 2022-11-09 13:48:40 -05:00
Code Releases Activity

update error_dump interface

Browse source
This commit is contained in:
Vyacheslav Alexeev 2020-05-09 18:04:04 +03:00
parent 4f632b9a52
commit 607e24fe50
4 changed files with 39 additions and 43 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

20
lib/puma/debug_logger.rb
View file

@ -22,28 +22,32 @@ module Puma
end end
# Any error has occured during debug mode. # Any error has occured during debug mode.
# +error+ is an exception object, +env+ the request,
# +options+ hash with additional options: # +options+ hash with additional options:
# - +force+ (default nil) to log info even if debug mode is turned off # - +force+ (default nil) to log info even if debug mode is turned off
# - +custom_message+ (default nil) custom string to print after title # - +error+ is an exception object
# - +env+ the request
# - +text+ (default nil) custom string to print in title
# and before all remaining info. # and before all remaining info.
# #
def error_dump(error, env=nil, options={}) def error_dump(options={})
return unless @debug || options[:force] return unless @debug || options[:force]
error = options[:error]
env = options[:env]
text = options[:text]
# #
# TODO: add all info we have about request # TODO: add all info we have about request
# #
string_block = [] string_block = []
formatted_text = " #{text}:" if text
custom_message = " #{options[:custom_message]}:" if options[:custom_message] formatted_error = " #{error.inspect}" if error
string_block << "#{Time.now}#{custom_message} #{error.inspect}" string_block << "#{Time.now}#{text}#{error.inspect}"
if env if env
string_block << "Handling request { #{env[REQUEST_METHOD]} #{env[REQUEST_PATH] || env[PATH_INFO]} } (#{env[HTTP_X_FORWARDED_FOR] || env[REMOTE_ADDR]})" string_block << "Handling request { #{env[REQUEST_METHOD]} #{env[REQUEST_PATH] || env[PATH_INFO]} } (#{env[HTTP_X_FORWARDED_FOR] || env[REMOTE_ADDR]})"
end end
string_block << error.backtrace string_block << error.backtrace if error
ioerr.puts string_block.join("\n") ioerr.puts string_block.join("\n")
end end

8
lib/puma/events.rb
View file

@ -79,7 +79,7 @@ module Puma
# Write +str+ to +@stderr+ # Write +str+ to +@stderr+
# #
def error(str) def error(str)
@stderr.puts format("ERROR: #{str}") @debug_logger.error_dump(text: format("ERROR: #{str}"))
exit 1 exit 1
end end
@ -92,7 +92,7 @@ module Puma
# parsing exception. # parsing exception.
# #
def parse_error(server, env, error) def parse_error(server, env, error)
@debug_logger.error_dump(error, env, custom_message: 'HTTP parse error, malformed request', force: true) @debug_logger.error_dump(error: error, env: env, text: 'HTTP parse error, malformed request', force: true)
end end
# An SSL error has occurred. # An SSL error has occurred.
@ -101,7 +101,7 @@ module Puma
# #
def ssl_error(server, peeraddr, peercert, error) def ssl_error(server, peeraddr, peercert, error)
subject = peercert ? peercert.subject : nil subject = peercert ? peercert.subject : nil
@debug_logger.error_dump(error, nil, custom_message: "SSL error, peer: #{peeraddr}, peer cert: #{subject}", force: true) @debug_logger.error_dump(error: error, text: "SSL error, peer: #{peeraddr}, peer cert: #{subject}", force: true)
end end
# An unknown error has occurred. # An unknown error has occurred.
@ -109,7 +109,7 @@ module Puma
# +kind+ some additional info, and +env+ the request. # +kind+ some additional info, and +env+ the request.
# #
def unknown_error(server, error, kind="Unknown", env=nil) def unknown_error(server, error, kind="Unknown", env=nil)
@debug_logger.error_dump(error, env, custom_message: kind, force: true) @debug_logger.error_dump(error: error, env: env, text: kind, force: true)
end end
def on_booted(&block) def on_booted(&block)

34
lib/puma/server.rb
View file

@ -217,7 +217,7 @@ module Puma
@events.parse_error self, client.env, e @events.parse_error self, client.env, e
rescue ConnectionError, EOFError => e rescue ConnectionError, EOFError => e
@debug_logger.error_dump(e, client.env) @debug_logger.error_dump(error: e, env: client.env)
client.close client.close
else else
if process_now if process_now
@ -298,17 +298,17 @@ module Puma
end end
rescue SystemCallError => e rescue SystemCallError => e
# TODO: check if we able to use client here # TODO: check if we able to use client here
@debug_logger.error_dump(e) @debug_logger.error_dump(error: e)
# nothing # nothing
rescue Errno::ECONNABORTED rescue Errno::ECONNABORTED
# TODO: check if we able to use client here # TODO: check if we able to use client here
@debug_logger.error_dump(e, nil, custom_message: 'Client closed the socket even before accept') @debug_logger.error_dump(error: e, text: 'Client closed the socket even before accept')
begin begin
io.close io.close
rescue => e rescue => e
Thread.current.purge_interrupt_queue if Thread.current.respond_to? :purge_interrupt_queue Thread.current.purge_interrupt_queue if Thread.current.respond_to? :purge_interrupt_queue
# TODO: check if we able to use client here # TODO: check if we able to use client here
@debug_logger.error_dump(e, nil) @debug_logger.error_dump(error: e)
end end
end end
end end
@ -327,7 +327,7 @@ module Puma
end end
graceful_shutdown if @status == :stop || @status == :restart graceful_shutdown if @status == :stop || @status == :restart
rescue Exception => e rescue Exception => e
@debug_logger.error_dump(e, force: true, custom_message: 'Exception handling servers') @debug_logger.error_dump(error: e, force: true, text: 'Exception handling servers')
ensure ensure
@check.close unless @check.closed? # Ruby 2.2 issue @check.close unless @check.closed? # Ruby 2.2 issue
@notify.close @notify.close
@ -405,7 +405,7 @@ module Puma
# The client disconnected while we were reading data # The client disconnected while we were reading data
rescue ConnectionError => e rescue ConnectionError => e
@debug_logger.error_dump(e, client.env, custom_message: 'The client disconnected while we were reading data') @debug_logger.error_dump(error: e, env: client.env, text: 'The client disconnected while we were reading data')
# Swallow them. The ensure tries to close +client+ down # Swallow them. The ensure tries to close +client+ down
# SSL handshake error # SSL handshake error
@ -443,7 +443,7 @@ module Puma
client.close if close_socket client.close if close_socket
rescue IOError, SystemCallError => e rescue IOError, SystemCallError => e
Thread.current.purge_interrupt_queue if Thread.current.respond_to? :purge_interrupt_queue Thread.current.purge_interrupt_queue if Thread.current.respond_to? :purge_interrupt_queue
@debug_logger.error_dump(e, client.env) @debug_logger.error_dump(error: e, env: client.env)
# Already closed # Already closed
rescue StandardError => e rescue StandardError => e
@events.unknown_error self, e, "Client" @events.unknown_error self, e, "Client"
@ -498,7 +498,7 @@ module Puma
# Client disconnects can result in an inability to get the # Client disconnects can result in an inability to get the
# peeraddr from the socket; default to localhost. # peeraddr from the socket; default to localhost.
addr = LOCALHOST_IP addr = LOCALHOST_IP
@debug_logger.error_dump(e, custom_message: 'Client disconnects can result in an inability to get the peeraddr from the socket') @debug_logger.error_dump(error: e, text: 'Client disconnects can result in an inability to get the peeraddr from the socket')
end end
# Set unix socket addrs to localhost # Set unix socket addrs to localhost
@ -574,7 +574,7 @@ module Puma
fast_write client, "\r\n".freeze fast_write client, "\r\n".freeze
rescue ConnectionError => e rescue ConnectionError => e
# noop, if we lost the socket we just won't send the early hints # noop, if we lost the socket we just won't send the early hints
@debug_logger.error_dump(e, env) @debug_logger.error_dump(error: e, env: env)
end end
} }
end end
@ -602,12 +602,12 @@ module Puma
rescue ThreadPool::ForceShutdown => e rescue ThreadPool::ForceShutdown => e
@events.unknown_error self, e, "Rack app", env @events.unknown_error self, e, "Rack app", env
@events.log "Detected force shutdown of a thread" @events.log "Detected force shutdown of a thread"
@debug_logger.error_dump(e, env) @debug_logger.error_dump(error: e, env: env)
status, headers, res_body = lowlevel_error(e, env, 503) status, headers, res_body = lowlevel_error(e, env, 503)
rescue Exception => e rescue Exception => e
@events.unknown_error self, e, "Rack app", env @events.unknown_error self, e, "Rack app", env
@debug_logger.error_dump(e, env) @debug_logger.error_dump(error: e, env: env)
status, headers, res_body = lowlevel_error(e, env, 500) status, headers, res_body = lowlevel_error(e, env, 500)
end end
@ -745,7 +745,7 @@ module Puma
client.flush client.flush
end end
rescue SystemCallError, IOError => e rescue SystemCallError, IOError => e
@debug_logger.error_dump(e, env) @debug_logger.error_dump(error: e, env: env)
raise ConnectionError, "Connection error detected during write" raise ConnectionError, "Connection error detected during write"
end end
@ -874,7 +874,7 @@ module Puma
@thread_pool << client @thread_pool << client
end end
rescue SystemCallError => e rescue SystemCallError => e
@debug_logger.error_dump(e) @debug_logger.error_dump(error: e)
end end
end end
end end
@ -901,9 +901,9 @@ module Puma
rescue IOError => e rescue IOError => e
# The server, in another thread, is shutting down # The server, in another thread, is shutting down
Thread.current.purge_interrupt_queue if Thread.current.respond_to? :purge_interrupt_queue Thread.current.purge_interrupt_queue if Thread.current.respond_to? :purge_interrupt_queue
@debug_logger.error_dump(e) @debug_logger.error_dump(error: e)
rescue RuntimeError => e rescue RuntimeError => e
@debug_logger.error_dump(e) @debug_logger.error_dump(error: e)
# Temporary workaround for https://bugs.ruby-lang.org/issues/13239 # Temporary workaround for https://bugs.ruby-lang.org/issues/13239
if e.message.include?('IOError') if e.message.include?('IOError')
Thread.current.purge_interrupt_queue if Thread.current.respond_to? :purge_interrupt_queue Thread.current.purge_interrupt_queue if Thread.current.respond_to? :purge_interrupt_queue
@ -937,14 +937,14 @@ module Puma
begin begin
n = io.syswrite str n = io.syswrite str
rescue Errno::EAGAIN, Errno::EWOULDBLOCK => e rescue Errno::EAGAIN, Errno::EWOULDBLOCK => e
@debug_logger.error_dump(e) @debug_logger.error_dump(error: e)
if !IO.select(nil, [io], nil, WRITE_TIMEOUT) if !IO.select(nil, [io], nil, WRITE_TIMEOUT)
raise ConnectionError, "Socket timeout writing data" raise ConnectionError, "Socket timeout writing data"
end end
retry retry
rescue Errno::EPIPE, SystemCallError, IOError => e rescue Errno::EPIPE, SystemCallError, IOError => e
@debug_logger.error_dump(e) @debug_logger.error_dump(error: e)
raise ConnectionError, "Socket timeout writing data" raise ConnectionError, "Socket timeout writing data"
end end

20
test/test_debug_logger.rb
View file

@ -5,14 +5,6 @@ class TestDebugLogger < Minitest::Test
@debug_logger = Puma::DebugLogger.stdio @debug_logger = Puma::DebugLogger.stdio
end end
def test_other_io
with_debug_mode do
debug_logger = Puma::DebugLogger.new(StringIO.new)
debug_logger.error_dump(StandardError.new('ready'))
assert_match %r!#<StandardError: ready>!, debug_logger.ioerr.string
end
end
def test_stdio def test_stdio
debug_logger = Puma::DebugLogger.stdio debug_logger = Puma::DebugLogger.stdio
@ -21,7 +13,7 @@ class TestDebugLogger < Minitest::Test
def test_error_dump_if_debug_false def test_error_dump_if_debug_false
_, err = capture_io do _, err = capture_io do
@debug_logger.error_dump(StandardError.new('ready')) @debug_logger.error_dump(text: 'blank')
end end
assert_empty err assert_empty err
@ -29,7 +21,7 @@ class TestDebugLogger < Minitest::Test
def test_error_dump_force def test_error_dump_force
_, err = capture_io do _, err = capture_io do
Puma::DebugLogger.stdio.error_dump(StandardError.new('ready'), nil, force: true) Puma::DebugLogger.stdio.error_dump(text: 'ready', force: true)
end end
assert_match %r!ready!, err assert_match %r!ready!, err
@ -38,7 +30,7 @@ class TestDebugLogger < Minitest::Test
def test_error_dump_with_only_error def test_error_dump_with_only_error
with_debug_mode do with_debug_mode do
_, err = capture_io do _, err = capture_io do
Puma::DebugLogger.stdio.error_dump(StandardError.new('ready'), nil) Puma::DebugLogger.stdio.error_dump(error: StandardError.new('ready'))
end end
assert_match %r!#<StandardError: ready>!, err assert_match %r!#<StandardError: ready>!, err
@ -54,17 +46,17 @@ class TestDebugLogger < Minitest::Test
} }
_, err = capture_io do _, err = capture_io do
Puma::DebugLogger.stdio.error_dump(StandardError.new, env) Puma::DebugLogger.stdio.error_dump(error: StandardError.new, env: env)
end end
assert_match %r!Handling request { GET /debug } \(8\.8\.8\.8\)!, err assert_match %r!Handling request { GET /debug } \(8\.8\.8\.8\)!, err
end end
end end
def test_error_dump_with_custom_message def test_error_dump_with_text
with_debug_mode do with_debug_mode do
_, err = capture_io do _, err = capture_io do
Puma::DebugLogger.stdio.error_dump(StandardError.new, nil, custom_message: 'The client disconnected while we were reading data') Puma::DebugLogger.stdio.error_dump(text: 'The client disconnected while we were reading data')
end end
assert_match %r!The client disconnected while we were reading data!, err assert_match %r!The client disconnected while we were reading data!, err