diff --git a/CHANGELOG.md b/CHANGELOG.md index 17876433..49321d8b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,7 @@ - Add the `form_actions` router configuration (#278). - [Deferred] Add native periodic task scheduling with multi-process leader election via `File#flock` by [@Abishekcs](https://github.com/Abishekcs) (#233). - [OpenAPI] Support optional attributes and `Array<>` syntax by [@ayushman1210](https://github.com/ayushman1210) (#228). +- [Errors] Add centralized error reporting interface via `Rage.errors` and `config.error_handlers` by [@Digvijay-x1](https://github.com/Digvijay-x1) (#275). ### Fixed diff --git a/lib/rage-rb.rb b/lib/rage-rb.rb index 17dbddf7..be19f263 100644 --- a/lib/rage-rb.rb +++ b/lib/rage-rb.rb @@ -40,6 +40,12 @@ def self.events Rage::Events end + # Shorthand to access {Rage::Errors Rage::Errors}. + # @return [Rage::Errors] + def self.errors + Rage::Errors + end + # Shorthand to access {Rage::SSE Rage::SSE}. # @return [Rage::SSE] def self.sse @@ -191,6 +197,7 @@ module ActiveRecord autoload :OpenAPI, "rage/openapi/openapi" autoload :Deferred, "rage/deferred/deferred" autoload :Events, "rage/events/events" + autoload :Errors, "rage/errors" autoload :PubSub, "rage/pubsub/pubsub" end diff --git a/lib/rage/application.rb b/lib/rage/application.rb index 56a4799a..4af66392 100644 --- a/lib/rage/application.rb +++ b/lib/rage/application.rb @@ -23,6 +23,7 @@ def call(env) response = @exception_app.call(400, e) rescue Exception => e + Rage::Errors.report(e) response = @exception_app.call(500, e) ensure diff --git a/lib/rage/cable/cable.rb b/lib/rage/cable/cable.rb index 56c0e625..4fab4d6f 100644 --- a/lib/rage/cable/cable.rb +++ b/lib/rage/cable/cable.rb @@ -128,7 +128,8 @@ def schedule_fiber(connection) end def log_error(e) - Rage.logger.error("Unhandled exception has occured - #{e.class} (#{e.message}):\n#{e.backtrace.join("\n")}") + Rage.logger.error("Unhandled exception has occurred - #{e.class} (#{e.message}):\n#{e.backtrace.join("\n")}") + Rage::Errors.report(e) end end diff --git a/lib/rage/cable/channel.rb b/lib/rage/cable/channel.rb index f9e752c7..8cc086ff 100644 --- a/lib/rage/cable/channel.rb +++ b/lib/rage/cable/channel.rb @@ -331,7 +331,8 @@ def set_up_periodic_timers Fiber.schedule do slice.each { |channel| callback.call(channel) } rescue => e - Rage.logger.error("Unhandled exception has occured - #{e.class} (#{e.message}):\n#{e.backtrace.join("\n")}") + Rage.logger.error("Unhandled exception has occurred - #{e.class} (#{e.message}):\n#{e.backtrace.join("\n")}") + Rage::Errors.report(e) end end end diff --git a/lib/rage/configuration.rb b/lib/rage/configuration.rb index 7335350a..509af5c0 100644 --- a/lib/rage/configuration.rb +++ b/lib/rage/configuration.rb @@ -219,6 +219,14 @@ def cable end # @!endgroup + # @!group Error Handler Configuration + # Allows configuring error handlers. + # @return [Rage::Configuration::ErrorHandlers] + def error_handlers + @error_handlers ||= ErrorHandlers.new + end + # @!endgroup + # @!group OpenAPI Configuration # Allows configuring OpenAPI settings. # @return [Rage::Configuration::OpenAPI] @@ -386,6 +394,60 @@ def validate_input!(obj) end end + class ErrorHandlers + # @private + def initialize + @objects = [] + end + + # @private + def objects + @objects.dup + end + + # Add a new error handler. + # Error handlers should respond to `#call` and accept one of: + # - `call(exception)` + # - `call(exception, context: {})` + # + # @param handler [#call] + # @return [self] + # @example + # Rage.configure do + # config.error_handlers << SentryReporter.new + # end + def <<(handler) + validate_input!(handler) + return self if @objects.include?(handler) + + @objects << handler + Rage::Errors.__send__(:__register_reporter, handler) + + self + end + + alias_method :push, :<< + + # Remove an error handler. + # @param handler [#call] the handler to remove + # @example + # handler = SentryReporter.new + # Rage.configure do + # config.error_handlers.delete(handler) + # end + def delete(handler) + deleted = @objects.delete(handler) + Rage::Errors.__send__(:__unregister_reporter, handler) if deleted + deleted + end + + private + + def validate_input!(handler) + raise ArgumentError, "error handler must respond to #call" unless handler.respond_to?(:call) + end + end + class Server # @!attribute port # Specify the port the server will listen on. diff --git a/lib/rage/deferred/task.rb b/lib/rage/deferred/task.rb index a1843a20..24968335 100644 --- a/lib/rage/deferred/task.rb +++ b/lib/rage/deferred/task.rb @@ -81,6 +81,8 @@ def __perform(context) true rescue Exception => e + Rage::Errors.report(e) + unless respond_to?(:__deferred_suppress_exception_logging?, true) && __deferred_suppress_exception_logging? Rage.logger.with_context(task_log_context) do Rage.logger.error("Deferred task failed with exception: #{e.class} (#{e.message}):\n#{e.backtrace.join("\n")}") diff --git a/lib/rage/errors.rb b/lib/rage/errors.rb index 3d1f2ba1..657f8081 100644 --- a/lib/rage/errors.rb +++ b/lib/rage/errors.rb @@ -1,4 +1,87 @@ +# frozen_string_literal: true + module Rage::Errors + ReporterEntry = Struct.new(:reporter, :method_name) + private_constant :ReporterEntry + + @reporters = [] + @next_reporter_id = 0 + + class << self + # Forward an exception to all registered reporters. + # + # @param exception [Exception] + # @param context [Hash] + # @return [nil] + def report(exception, context: {}) + return if @reporters.empty? + return if exception.instance_variable_defined?(:@_rage_error_reported) + + ensure_backtrace(exception) + + @reporters.each do |entry| + __send__(entry.method_name, entry.reporter, exception, context) + rescue => e + Rage.logger.error("Error reporter #{entry.reporter.class} failed while reporting #{exception.class}: #{e.class} (#{e.message})") + end + + exception.instance_variable_set(:@_rage_error_reported, true) unless exception.frozen? + + nil + end + + # @private + def __register_reporter(reporter) + raise ArgumentError, "error handler must respond to #call" unless reporter.respond_to?(:call) + + reporter_id = @next_reporter_id + @next_reporter_id += 1 + method_name = :"__report_#{reporter_id}" + + arguments = Rage::Internal.build_arguments( + reporter.method(:call), + { context: "context" } + ) + call_arguments = arguments.empty? ? "" : ", #{arguments}" + + singleton_class.class_eval <<~RUBY, __FILE__, __LINE__ + 1 + def #{method_name}(reporter, exception, context) + reporter.call(exception#{call_arguments}) + end + RUBY + + @reporters << ReporterEntry.new(reporter, method_name) + + self + end + + # @private + def __unregister_reporter(reporter) + @reporters.delete_if do |entry| + next false unless entry.reporter == reporter + + singleton_class.remove_method(entry.method_name) if singleton_class.method_defined?(entry.method_name) + true + end + + self + end + + private + + def ensure_backtrace(exception) + return if exception.frozen? + return unless exception.backtrace.nil? + + begin + raise exception + rescue exception.class + end + end + + private :__register_reporter, :__unregister_reporter + end + class BadRequest < StandardError end diff --git a/lib/rage/events/subscriber.rb b/lib/rage/events/subscriber.rb index cff45cbe..0eed1e5f 100644 --- a/lib/rage/events/subscriber.rb +++ b/lib/rage/events/subscriber.rb @@ -90,7 +90,12 @@ def __call(event, context: nil) Rage.logger.with_context(self.class.__log_context) do Rage.logger.error("Subscriber failed with exception: #{e.class} (#{e.message}):\n#{e.backtrace.join("\n")}") end - raise e if self.class.__is_deferred + + if self.class.__is_deferred + raise e + else + Rage::Errors.report(e) + end end private diff --git a/lib/rage/middleware/fiber_wrapper.rb b/lib/rage/middleware/fiber_wrapper.rb index f77db773..3f8a65a3 100644 --- a/lib/rage/middleware/fiber_wrapper.rb +++ b/lib/rage/middleware/fiber_wrapper.rb @@ -20,6 +20,7 @@ def call(env) rescue Exception => e exception_str = "#{e.class} (#{e.message}):\n#{e.backtrace.join("\n")}" Rage.logger << exception_str + Rage::Errors.report(e) if Rage.env.development? [500, {}, [exception_str]] else diff --git a/lib/rage/pubsub/adapters/redis.rb b/lib/rage/pubsub/adapters/redis.rb index 1f4220f4..441f1540 100644 --- a/lib/rage/pubsub/adapters/redis.rb +++ b/lib/rage/pubsub/adapters/redis.rb @@ -136,6 +136,7 @@ def poll rescue RedisClient::Error => e Rage.logger.error("Subscriber error: #{e.message} (#{e.class})") + Rage::Errors.report(e) sleep error_backoff_intervals.next rescue SystemCallError => e @stopping ? break : raise(e) diff --git a/lib/rage/sse/application.rb b/lib/rage/sse/application.rb index 60ecd0db..cbc49266 100644 --- a/lib/rage/sse/application.rb +++ b/lib/rage/sse/application.rb @@ -63,6 +63,7 @@ def start_stream(connection) end rescue => e Rage.logger.error("SSE stream failed with exception: #{e.class} (#{e.message}):\n#{e.backtrace.join("\n")}") + Rage::Errors.report(e) ensure Iodine.task_dec! end diff --git a/lib/rage/telemetry/tracer.rb b/lib/rage/telemetry/tracer.rb index fda6bca4..1f92abae 100644 --- a/lib/rage/telemetry/tracer.rb +++ b/lib/rage/telemetry/tracer.rb @@ -74,6 +74,7 @@ def #{tracer_name(span.id)}(#{parameters}) #{calls_chain} rescue Exception => e Rage.logger.error("Telemetry handler failed with error \#{e}:\\n\#{e.backtrace.join("\\n")}") + Rage::Errors.report(e) end unless yield_called diff --git a/spec/deferred/task_spec.rb b/spec/deferred/task_spec.rb index 0310e56c..1abae86e 100644 --- a/spec/deferred/task_spec.rb +++ b/spec/deferred/task_spec.rb @@ -355,6 +355,7 @@ def perform(arg, kwarg:) allow(Rage::Deferred::Context).to receive(:get_log_context).with(context).and_return({}) allow(task).to receive(:perform).and_raise(error) allow(error).to receive(:backtrace).and_return(["line 1", "line 2"]) + allow(Rage::Errors).to receive(:report) end it "logs the error" do @@ -362,6 +363,11 @@ def perform(arg, kwarg:) expect(logger).to have_received(:error).with("Deferred task failed with exception: StandardError (Something went wrong):\nline 1\nline 2") end + it "reports the error" do + task.__perform(context) + expect(Rage::Errors).to have_received(:report).with(error) + end + it "returns the exception" do expect(task.__perform(context)).to be(error) end diff --git a/spec/errors_spec.rb b/spec/errors_spec.rb new file mode 100644 index 00000000..f18a2f6b --- /dev/null +++ b/spec/errors_spec.rb @@ -0,0 +1,151 @@ +# frozen_string_literal: true + +RSpec.describe Rage::Errors do + around do |example| + original_reporters = described_class.instance_variable_get(:@reporters) + original_next_reporter_id = described_class.instance_variable_get(:@next_reporter_id) + described_class.instance_variable_set(:@reporters, []) + described_class.instance_variable_set(:@next_reporter_id, 0) + example.run + ensure + described_class.instance_variable_set(:@reporters, original_reporters) + described_class.instance_variable_set(:@next_reporter_id, original_next_reporter_id) + end + + let(:error_handlers) { Rage::Configuration.new.error_handlers } + + describe "configuration integration" do + it "is available via config.error_handlers" do + expect(Rage::Configuration.new.error_handlers).to be_an_instance_of(Rage::Configuration::ErrorHandlers) + end + + it "is available via Rage.errors" do + expect(Rage.errors).to eq(described_class) + end + + it "requires error handlers to respond to #call" do + expect { + error_handlers << Object.new + }.to raise_error(ArgumentError, "error handler must respond to #call") + end + + it "allows removing a registered error handler" do + call_count = 0 + reporter = Class.new do + define_method(:call) { |_exception| call_count += 1 } + end.new + + error_handlers << reporter + error_handlers.delete(reporter) + + described_class.report(StandardError.new("test")) + + expect(call_count).to eq(0) + end + end + + describe ".report" do + let(:logger) { double(error: nil) } + + before do + allow(Rage).to receive(:logger).and_return(logger) + end + + it "returns nil when no reporters are registered" do + expect(described_class.report(StandardError.new("test"))).to be_nil + end + + it "calls a simple reporter with exception only" do + reporter = Class.new do + attr_reader :exception + + def call(exception) + @exception = exception + end + end.new + + error = StandardError.new("test") + error_handlers << reporter + described_class.report(error, context: { user_id: 42 }) + + expect(reporter.exception).to be(error) + end + + it "calls a reporter with context when supported" do + reporter = Class.new do + attr_reader :exception, :context + + def call(exception, context: {}) + @exception = exception + @context = context + end + end.new + + error = StandardError.new("test") + error_handlers << reporter + described_class.report(error, context: { user_id: 42 }) + + expect(reporter.exception).to be(error) + expect(reporter.context).to eq({ user_id: 42 }) + end + + it "adds backtrace for manually-created exceptions" do + reporter = Class.new do + attr_reader :exception + + def call(exception) + @exception = exception + end + end.new + + error = StandardError.new("test") + expect(error.backtrace).to be_nil + + error_handlers << reporter + described_class.report(error) + + expect(reporter.exception.backtrace).to be_an(Array) + expect(reporter.exception.backtrace).not_to be_empty + end + + it "continues reporting when one reporter fails" do + failed_reporter = Class.new do + def call(_exception) + raise "boom" + end + end.new + + successful_reporter = Class.new do + attr_reader :exception + + def call(exception) + @exception = exception + end + end.new + + error = StandardError.new("test") + error_handlers << failed_reporter + error_handlers << successful_reporter + + described_class.report(error) + + expect(successful_reporter.exception).to be(error) + expect(logger).to have_received(:error).with(/Error reporter .* failed while reporting StandardError: RuntimeError \(boom\)/) + end + + it "does not report the same exception twice" do + call_count = 0 + reporter = Class.new do + define_method(:call) { |_exception| call_count += 1 } + end.new + + error = StandardError.new("test") + error_handlers << reporter + + described_class.report(error) + described_class.report(error) + + expect(call_count).to eq(1) + end + end +end diff --git a/spec/events/deferred_spec.rb b/spec/events/deferred_spec.rb index 0f226a8b..815dba1e 100644 --- a/spec/events/deferred_spec.rb +++ b/spec/events/deferred_spec.rb @@ -74,11 +74,14 @@ def call(event) context "with exception" do it "it re-raises the exception" do + allow(Rage::Errors).to receive(:report) expect(logger).to receive(:error).with(/Subscriber failed with exception: RuntimeError/) expect { EventsDeferredSpec::EventWithExceptionSubscriber.new.perform(EventsDeferredSpec::EventWithException.new) }.to raise_error(RuntimeError, "test") + + expect(Rage::Errors).not_to have_received(:report) end end end diff --git a/spec/events/publish_spec.rb b/spec/events/publish_spec.rb index 298cb118..bbc862e1 100644 --- a/spec/events/publish_spec.rb +++ b/spec/events/publish_spec.rb @@ -232,6 +232,7 @@ class EventWithAppendSubscriber < BaseSubscriber context "with exception inside subscriber" do it "correctly handles events" do expect(logger).to receive(:error).with(/test error/) + expect(Rage::Errors).to receive(:report).with(instance_of(RuntimeError)) expect { described_class.publish(EventsPublishSpec::EventWithException.new) diff --git a/spec/pubsub/adapters/redis_spec.rb b/spec/pubsub/adapters/redis_spec.rb index ccb6f821..c8fb1364 100644 --- a/spec/pubsub/adapters/redis_spec.rb +++ b/spec/pubsub/adapters/redis_spec.rb @@ -236,9 +236,11 @@ poller << block end + allow_any_instance_of(described_class).to receive(:sleep) allow(Iodine).to receive(:on_state).with(:start_shutdown).and_yield allow(logger).to receive(:info?).and_return(false) + allow(logger).to receive(:error) allow(Rage).to receive(:logger).and_return(logger) end @@ -356,5 +358,16 @@ subject end + + it "reports redis subscriber errors" do + allow(mock_redis).to receive(:blocking_call).and_invoke( + proc { raise RedisClient::CannotConnectError, "redis down" }, + proc { raise Errno::ECONNRESET } + ) + + expect(Rage::Errors).to receive(:report).with(instance_of(RedisClient::CannotConnectError)) + + subject + end end end diff --git a/spec/sse/application_spec.rb b/spec/sse/application_spec.rb index f3c6ee7e..edb860b0 100644 --- a/spec/sse/application_spec.rb +++ b/spec/sse/application_spec.rb @@ -56,12 +56,15 @@ def open? logger = double("logger") allow(Rage).to receive(:logger).and_return(logger) allow(logger).to receive(:error) + allow(Rage::Errors).to receive(:report) expect(Iodine).to receive(:task_inc!) expect(Iodine).to receive(:task_dec!) app = described_class.new(stream) app.on_open(connection) + + expect(Rage::Errors).to have_received(:report).with(instance_of(RuntimeError)) end end diff --git a/spec/telemetry/tracer_spec.rb b/spec/telemetry/tracer_spec.rb index f56d9981..f2af2f5a 100644 --- a/spec/telemetry/tracer_spec.rb +++ b/spec/telemetry/tracer_spec.rb @@ -271,6 +271,7 @@ def self.test_instrumentation end it "logs the error" do + expect(Rage::Errors).to receive(:report).with(instance_of(RuntimeError)) expect(Rage.logger).to receive(:error) do |msg| expect(msg).to match(/Telemetry handler failed with error/) expect(msg).to include("test error") @@ -304,6 +305,7 @@ def self.test_instrumentation end it "logs the error" do + expect(Rage::Errors).to receive(:report).with(instance_of(RuntimeError)) expect(Rage.logger).to receive(:error) do |msg| expect(msg).to match(/Telemetry handler failed with error/) expect(msg).to include("test error")