github-mirrors/logstash
1
0
Fork 0
mirror of https://github.com/elastic/logstash.git synced 2025-04-24 14:47:19 -04:00
Code Issues Projects Releases Packages Wiki Activity

Improve error handling in API / Rack App.

Browse source 
Setting error handling conditions in sinatra dynamically is not possible.
The values such as :show_exceptions get set, but have no effect.
This is esp. important in testing where we want failures to raise exceptions.
Otherwise, debugging is a matter of parsing instructable HTML responses containing
the debug info.

We do not want this behavior by default however, as doing so would mean a single API
bug would take down a production app.

This change adds a new agent setting (not CLI setting) 'http.environment' that is defaulted to 'production'.
If set to 'test' exceptions get raised.

This change also removes sinatra error handlers that previously did nothing, and injects
custom rack middleware to properly log and handle errors.

Fixes #5411
This commit is contained in:
Andrew Cholakian 2016-05-31 16:11:12 -05:00
parent f4fd8943e7
commit f0dfea9d80
9 changed files with 188 additions and 21 deletions
Download patch file Download diff file Expand all files Collapse all files

3
logstash-core/lib/logstash/agent.rb
View file

@ -38,6 +38,7 @@ class LogStash::Agent
@node_name = setting("node.name")
@http_host = setting("http.host")
@http_port = setting("http.port")
@http_environment = setting("http.environment")
@config_loader = LogStash::Config::Loader.new(@logger)
@reload_interval = setting("config.reload.interval")
@ -129,7 +130,7 @@ class LogStash::Agent
private
def start_webserver
options = {:http_host => @http_host, :http_port => @http_port }
options = {:http_host => @http_host, :http_port => @http_port, :http_environment => @http_environment }
@webserver = LogStash::WebServer.new(@logger, options)
Thread.new(@webserver) do |webserver|
LogStash::Util.set_thread_name("Api Webserver")

17
logstash-core/lib/logstash/api/modules/base.rb
View file

@ -7,15 +7,16 @@ module LogStash
class Base < ::Sinatra::Base
helpers AppHelpers
# These options never change
# Sinatra isn't good at letting you change internal settings at runtime
# which is a requirement. We always propagate errors up and catch them
# in a custom rack handler in the RackApp class
set :environment, :production
set :raise_errors, true
set :show_exceptions, false
attr_reader :factory
if settings.environment != :production
set :raise_errors, true
set :show_exceptions, :after_handler
end
include LogStash::Util::Loggable
helpers AppHelpers
@ -31,12 +32,6 @@ module LogStash
text = as == :string ? "" : {}
respond_with(text, :as => as)
end
error do
e = env['sinatra.error']
logger.error(e.message, :url => request.url, :ip => request.ip, :params => request.params, :class => e.class.name, :backtrace => e.backtrace)
end
end
end
end

2
logstash-core/lib/logstash/api/modules/node.rb
View file

@ -1,4 +1,6 @@
# encoding: utf-8
require "logstash/api/modules/base"
module LogStash
module Api
module Modules

78
logstash-core/lib/logstash/api/rack_app.rb
View file

@ -1,3 +1,5 @@
require "sinatra"
require "rack"
require "logstash/api/modules/base"
require "logstash/api/modules/node"
require "logstash/api/modules/node_stats"
@ -8,9 +10,83 @@ require "logstash/api/modules/stats"
module LogStash
module Api
module RackApp
def self.app
# Cabin is not compatible with CommonLogger, and this gives us more control anyway
METADATA_FIELDS = [:request_method, :path_info, :query_string, :http_version, :http_accept].freeze
def self.log_metadata(status, env)
METADATA_FIELDS.reduce({:status => status}) do |acc, field|
acc[field] = env[field.to_s.upcase]
acc
end
end
class ApiLogger
LOG_MESSAGE = "API HTTP Request".freeze
def initialize(app, logger)
@app = app
@logger = logger
end
def call(env)
res = @app.call(env)
status, headers, body = res
if fatal_error?(status)
@logger.warn? && @logger.warn(LOG_MESSAGE, RackApp.log_metadata(status, env))
else
@logger.info? && @logger.info(LOG_MESSAGE, RackApp.log_metadata(status, env))
end
res
end
def fatal_error?(status)
status >= 500 && status < 600
end
end
class ApiErrorHandler
LOG_MESSAGE = "Internal API server error".freeze
def initialize(app, logger)
@app = app
@logger = logger
end
def call(env)
@app.call(env)
rescue => e
body = RackApp.log_metadata(500, env).
merge({
:error => "Unexpected Internal Error",
:class => e.class.name,
:message => e.message,
:backtrace => e.backtrace
})
@logger.error(LOG_MESSAGE, body)
[500,
{'Content-Type' => 'application/json'},
[LogStash::Json.dump(body)]
]
end
end
def self.app(logger, environment)
namespaces = rack_namespaces
Rack::Builder.new do
# Custom logger object. Rack CommonLogger does not work with cabin
use ApiLogger, logger
# In test env we want errors to propogate up the chain
# so we get easy to understand test failures.
# In production / dev we don't want a bad API endpoint
# to crash the process
if environment != "test"
use ApiErrorHandler, logger
end
run LogStash::Api::Modules::Root
namespaces.each_pair do |namespace, app|
map(namespace) do

2
logstash-core/lib/logstash/api/service.rb
View file

@ -26,7 +26,7 @@ module LogStash
end
def started?
!@snapshot.nil? && has_counters?
!@snapshot.nil? && has_counters?
end
def update(snapshot)

1
logstash-core/lib/logstash/environment.rb
View file

@ -29,6 +29,7 @@ module LogStash
Setting::String.new("log.format", "plain", true, ["json", "plain"]),
Setting::String.new("http.host", "127.0.0.1"),
Setting::Port.new("http.port", 9600),
Setting::String.new("http.environment", "production"),
].each {|setting| SETTINGS.register(setting) }
module Environment

9
logstash-core/lib/logstash/webserver.rb
View file

@ -1,25 +1,25 @@
# encoding: utf-8
require "puma"
require "puma/server"
require "sinatra"
require "rack"
require "logstash/api/rack_app"
module LogStash
class WebServer
extend Forwardable
attr_reader :logger, :status, :config, :options, :cli_options, :runner, :binder, :events, :http_host, :http_port
attr_reader :logger, :status, :config, :options, :cli_options, :runner, :binder, :events, :http_host, :http_port, :http_environment
def_delegator :@runner, :stats
DEFAULT_HOST = "127.0.0.1".freeze
DEFAULT_PORT = 9600.freeze
DEFAULT_ENVIRONMENT = 'production'.freeze
def initialize(logger, options={})
@logger = logger
@http_host = options[:http_host] || DEFAULT_HOST
@http_port = options[:http_port] || DEFAULT_PORT
@http_environment = options[:http_environment] || DEFAULT_ENVIRONMENT
@options = {}
@cli_options = options.merge({ :rackup => ::File.join(::File.dirname(__FILE__), "api", "init.ru"),
:binds => ["tcp://#{http_host}:#{http_port}"],
@ -37,7 +37,8 @@ module LogStash
stop # Just in case
@server = ::Puma::Server.new(LogStash::Api::RackApp.app)
app = LogStash::Api::RackApp.app(logger, http_environment)
@server = ::Puma::Server.new(app)
@server.add_tcp_listener(http_host, http_port)
@server.run.join

88
logstash-core/spec/api/lib/rack_app_spec.rb Normal file
View file

@ -0,0 +1,88 @@
require "logstash/api/rack_app"
require "rack/test"
describe LogStash::Api::RackApp do
include Rack::Test::Methods
class DummyApp
class RaisedError < StandardError; end
def call(env)
case env["PATH_INFO"]
when "/good-page"
[200, {}, ["200 OK"]]
when "/service-unavailable"
[503, {}, ["503 service unavailable"]]
when "/raise-error"
raise RaisedError, "Error raised"
else
[404, {}, ["404 Page not found"]]
end
end
end
let(:logger) { Cabin::Channel.get }
describe LogStash::Api::RackApp::ApiErrorHandler do
let(:app) do
# Scoping in rack builder is weird, these need to be locals
rack_class = described_class
rack_logger = logger
Rack::Builder.new do
use rack_class, rack_logger
run DummyApp.new
end
end
it "should let good requests through as normal" do
get "/good-page"
expect(last_response).to be_ok
end
it "should let through 5xx codes" do
get "/service-unavailable"
expect(last_response.status).to eql(503)
end
describe "raised exceptions" do
before do
allow(logger).to receive(:error).with(any_args)
get "/raise-error"
end
it "should return a 500 error" do
expect(last_response.status).to eql(500)
end
it "should return valid JSON" do
expect { LogStash::Json.load(last_response.body) }.not_to raise_error
end
it "should log the error" do
expect(logger).to have_received(:error).with(LogStash::Api::RackApp::ApiErrorHandler::LOG_MESSAGE, anything).once
end
end
end
describe LogStash::Api::RackApp::ApiLogger do
let(:app) do
# Scoping in rack builder is weird, these need to be locals
rack_class = described_class
rack_logger = logger
Rack::Builder.new do
use rack_class, rack_logger
run DummyApp.new
end
end
it "should log good requests as info" do
expect(logger).to receive(:info).with(LogStash::Api::RackApp::ApiLogger::LOG_MESSAGE, anything).once
get "/good-page"
end
it "should log 5xx requests as warnings" do
expect(logger).to receive(:warn).with(LogStash::Api::RackApp::ApiLogger::LOG_MESSAGE, anything).once
get "/service-unavailable"
end
end
end

9
logstash-core/spec/api/spec_helper.rb
View file

@ -46,6 +46,7 @@ class LogStashRunner
"log.level" => "debug",
"node.name" => "test_agent",
"http.port" => rand(9600..9700),
"http.environment" => "test",
"config.string" => @config_str,
"pipeline.batch.size" => 1,
"pipeline.workers" => 1
@ -60,7 +61,8 @@ class LogStashRunner
@runner = Thread.new(agent) do |_agent|
_agent.execute
end
wait_until_snapshot_received
wait_until_ready
end
def stop
@ -71,8 +73,9 @@ class LogStashRunner
private
def wait_until_snapshot_received
while !LogStash::Api::Service.instance.started? do
def wait_until_ready
# Wait until the service and pipeline have started
while !(LogStash::Api::Service.instance.started? && agent.pipelines["main"].running?) do
sleep 0.5
end
end