From 8cbc19d86b1826b61f30211eb8b018d8173a087a Mon Sep 17 00:00:00 2001 From: Jean Boussier Date: Wed, 10 Nov 2021 15:21:27 +0100 Subject: [PATCH] Rails standardized error reporting interface Fix: https://github.com/rails/rails/issues/43472 The reporter is held by the executor, but the `Rails` module provides a nicer `Rails.error` shortcut. For ease of use, two block based specialized methods are exposed. `handle`, which swallow errors and forward them to the subscribers: ```ruby Rails.error.handle do 1 + '1' # raises TypeError end 1 + 1 # This will be executed ``` `record`, which forward the errors to the subscribes but let it continue rewinding the call stack: ```ruby Rails.error.record do 1 + '1' # raises TypeError end 1 + 1 # This won't be executed. ``` For cases where the blocked based API isn't suitable, the lower level `report` method can be used: ```ruby Rails.error.report(error, handled: true / false) ``` --- .../action_dispatch/middleware/executor.rb | 3 + activesupport/lib/active_support.rb | 1 + .../lib/active_support/error_reporter.rb | 109 +++++++++++++++ .../lib/active_support/execution_wrapper.rb | 8 ++ activesupport/test/error_reporter_test.rb | 131 ++++++++++++++++++ activesupport/test/executor_test.rb | 24 ++++ railties/lib/rails.rb | 4 + railties/lib/rails/application/bootstrap.rb | 5 +- 8 files changed, 284 insertions(+), 1 deletion(-) create mode 100644 activesupport/lib/active_support/error_reporter.rb create mode 100644 activesupport/test/error_reporter_test.rb diff --git a/actionpack/lib/action_dispatch/middleware/executor.rb b/actionpack/lib/action_dispatch/middleware/executor.rb index 129b18d3d9..85326e313b 100644 --- a/actionpack/lib/action_dispatch/middleware/executor.rb +++ b/actionpack/lib/action_dispatch/middleware/executor.rb @@ -13,6 +13,9 @@ module ActionDispatch begin response = @app.call(env) returned = response << ::Rack::BodyProxy.new(response.pop) { state.complete! } + rescue => error + @executor.error_reporter.report(error, handled: false) + raise ensure state.complete! unless returned end diff --git a/activesupport/lib/active_support.rb b/activesupport/lib/active_support.rb index f148992690..c0e8fd7cbd 100644 --- a/activesupport/lib/active_support.rb +++ b/activesupport/lib/active_support.rb @@ -43,6 +43,7 @@ module ActiveSupport autoload :ExecutionContext autoload :ExecutionWrapper autoload :Executor + autoload :ErrorReporter autoload :FileUpdateChecker autoload :EventedFileUpdateChecker autoload :ForkTracker diff --git a/activesupport/lib/active_support/error_reporter.rb b/activesupport/lib/active_support/error_reporter.rb new file mode 100644 index 0000000000..d09cde0d0b --- /dev/null +++ b/activesupport/lib/active_support/error_reporter.rb @@ -0,0 +1,109 @@ +# frozen_string_literal: true + +module ActiveSupport + # +ActiveSupport::ErrorReporter+ is a common interface for error reporting services. + # + # To rescue and report any unhandled error, you can use the +handle+ method: + # + # Rails.error.handle do + # do_something! + # end + # + # If an error is raised, it will be reported and swallowed. + # + # Alternatively if you want to report the error but not swallow it, you can use `record` + # + # Rails.error.record do + # do_something! + # end + # + # Both methods can be restricted to only handle a specific exception class + # + # maybe_tags = Rails.error.handle(Redis::BaseError) { redis.get("tags) } + # + # You can also pass some extra context information that may be used by the error subscribers: + # + # Rails.error.handle(context: { section: "admin" }) do + # # ... + # end + # + # Additionally a +severity+ can be passed along to communicate how important the error report is. + # +severity+ can be one of +:error+, +:warning+ or +:info+. Handled errors default to the +:warning+ + # severity, and unhandled ones to +error+. + class ErrorReporter + SEVERITIES = %i(error warning info) + + attr_accessor :logger + + def initialize(*subscribers, logger: nil) + @subscribers = subscribers.flatten + @logger = logger + end + + # Report any unhandled exception, and swallow it. + # + # Rails.error.handle do + # 1 + '1' + # end + # + def handle(error_class = StandardError, severity: :warning, context: {}) + yield + rescue error_class => error + report(error, handled: true, severity: severity, context: context) + nil + end + + def record(error_class = StandardError, severity: :error, context: {}) + yield + rescue error_class => error + report(error, handled: false, severity: severity, context: context) + raise + end + + # Register a new error subscriber. The subscriber must respond to + # + # report(Exception, handled: Boolean, context: Hash) + # + # The +report+ method +should+ never raise an error. + def subscribe(subscriber) + unless subscriber.respond_to?(:report) + raise ArgumentError, "Error subscribers must respond to #report" + end + @subscribers << subscriber + end + + # Update the execution context that is accessible to error subscribers + # + # Rails.error.set_context(section: "checkout", user_id: @user.id) + # + # See +ActiveSupport::ExecutionContext.set+ + def set_context(...) + ActiveSupport::ExecutionContext.set(...) + end + + # When the block based +handle+ and +record+ methods are not suitable, you can directly use +report+ + # + # Rails.error.report(error, handled: true) + def report(error, handled:, severity: handled ? :warning : :error, context: {}) + unless SEVERITIES.include?(severity) + raise ArgumentError, "severity must be one of #{SEVERITIES.map(&:inspect).join(", ")}, got: #{severity.inspect}" + end + + full_context = ActiveSupport::ExecutionContext.to_h.merge(context) + @subscribers.each do |subscriber| + subscriber.report(error, handled: handled, severity: severity, context: full_context) + rescue => subscriber_error + if logger + logger.fatal( + "Error subscriber raised an error: #{subscriber_error.message} (#{subscriber_error.class})\n" + + subscriber_error.backtrace.join("\n") + ) + else + raise + end + end + + nil + end + end +end diff --git a/activesupport/lib/active_support/execution_wrapper.rb b/activesupport/lib/active_support/execution_wrapper.rb index 36e80b23c7..8081f9ffb9 100644 --- a/activesupport/lib/active_support/execution_wrapper.rb +++ b/activesupport/lib/active_support/execution_wrapper.rb @@ -1,5 +1,6 @@ # frozen_string_literal: true +require "active_support/error_reporter" require "active_support/callbacks" require "concurrent/hash" @@ -86,6 +87,9 @@ module ActiveSupport instance = run! begin yield + rescue => error + error_reporter.report(error, handled: false) + raise ensure instance.complete! end @@ -105,6 +109,10 @@ module ActiveSupport attr_accessor :active end + def self.error_reporter + @error_reporter ||= ActiveSupport::ErrorReporter.new + end + def self.inherited(other) # :nodoc: super other.active = Concurrent::Hash.new diff --git a/activesupport/test/error_reporter_test.rb b/activesupport/test/error_reporter_test.rb new file mode 100644 index 0000000000..300aed8a85 --- /dev/null +++ b/activesupport/test/error_reporter_test.rb @@ -0,0 +1,131 @@ +# frozen_string_literal: true + +require_relative "abstract_unit" +require "active_support/execution_context/test_helper" + +class ErrorReporterTest < ActiveSupport::TestCase + # ExecutionContext is automatically reset in Rails app via executor hooks set in railtie + # But not in Active Support's own test suite. + include ActiveSupport::ExecutionContext::TestHelper + + class ErrorSubscriber + attr_reader :events + + def initialize + @events = [] + end + + def report(error, handled:, severity:, context:) + @events << [error, handled, severity, context] + end + end + + setup do + @reporter = ActiveSupport::ErrorReporter.new + @subscriber = ErrorSubscriber.new + @reporter.subscribe(@subscriber) + @error = ArgumentError.new("Oops") + end + + test "receives the execution context" do + @reporter.set_context(section: "admin") + error = ArgumentError.new("Oops") + @reporter.report(error, handled: true) + assert_equal [[error, true, :warning, { section: "admin" }]], @subscriber.events + end + + test "passed context has priority over the execution context" do + @reporter.set_context(section: "admin") + error = ArgumentError.new("Oops") + @reporter.report(error, handled: true, context: { section: "public" }) + assert_equal [[error, true, :warning, { section: "public" }]], @subscriber.events + end + + test "#handle swallow and report any unhandled error" do + error = ArgumentError.new("Oops") + @reporter.handle do + raise error + end + assert_equal [[error, true, :warning, {}]], @subscriber.events + end + + test "#handle can be scoped to an exception class" do + assert_raises ArgumentError do + @reporter.handle(NameError) do + raise ArgumentError + end + end + assert_equal [], @subscriber.events + end + + test "#record report any unhandled error and re-raise them" do + error = ArgumentError.new("Oops") + assert_raises ArgumentError do + @reporter.record do + raise error + end + end + assert_equal [[error, false, :error, {}]], @subscriber.events + end + + test "#record can be scoped to an exception class" do + assert_raises ArgumentError do + @reporter.record(NameError) do + raise ArgumentError + end + end + assert_equal [], @subscriber.events + end + + test "can have multiple subscribers" do + second_subscriber = ErrorSubscriber.new + @reporter.subscribe(second_subscriber) + + error = ArgumentError.new("Oops") + @reporter.report(error, handled: true) + + assert_equal 1, @subscriber.events.size + assert_equal 1, second_subscriber.events.size + end + + test "handled errors default to :warning severity" do + @reporter.report(@error, handled: true) + assert_equal :warning, @subscriber.events.dig(0, 2) + end + + test "unhandled errors default to :error severity" do + @reporter.report(@error, handled: false) + assert_equal :error, @subscriber.events.dig(0, 2) + end + + class FailingErrorSubscriber + Error = Class.new(StandardError) + + def initialize(error) + @error = error + end + + def report(_error, handled:, severity:, context:) + raise @error + end + end + + test "subscriber errors are re-raised if no logger is set" do + subscriber_error = FailingErrorSubscriber::Error.new("Big Oopsie") + @reporter.subscribe(FailingErrorSubscriber.new(subscriber_error)) + assert_raises FailingErrorSubscriber::Error do + @reporter.report(@error, handled: true) + end + end + + test "subscriber errors are logged if a logger is set" do + subscriber_error = FailingErrorSubscriber::Error.new("Big Oopsie") + @reporter.subscribe(FailingErrorSubscriber.new(subscriber_error)) + log = StringIO.new + @reporter.logger = ActiveSupport::Logger.new(log) + @reporter.report(@error, handled: true) + + expected = "Error subscriber raised an error: Big Oopsie (ErrorReporterTest::FailingErrorSubscriber::Error)" + assert_equal expected, log.string.lines.first.chomp + end +end diff --git a/activesupport/test/executor_test.rb b/activesupport/test/executor_test.rb index ac87780b23..faad49cc12 100644 --- a/activesupport/test/executor_test.rb +++ b/activesupport/test/executor_test.rb @@ -6,6 +6,30 @@ class ExecutorTest < ActiveSupport::TestCase class DummyError < RuntimeError end + class ErrorSubscriber + attr_reader :events + + def initialize + @events = [] + end + + def report(error, handled:, severity:, context:) + @events << [error, handled, severity, context] + end + end + + def test_wrap_report_errors + subscriber = ErrorSubscriber.new + executor.error_reporter.subscribe(subscriber) + error = DummyError.new("Oops") + assert_raises DummyError do + executor.wrap do + raise error + end + end + assert_equal [[error, false, :error, {}]], subscriber.events + end + def test_wrap_invokes_callbacks called = [] executor.to_run { called << :run } diff --git a/railties/lib/rails.rb b/railties/lib/rails.rb index de7c21931a..8677d12adb 100644 --- a/railties/lib/rails.rb +++ b/railties/lib/rails.rb @@ -81,6 +81,10 @@ module Rails @_env = ActiveSupport::EnvironmentInquirer.new(environment) end + def error + application && application.executor.error_reporter + end + # Returns all Rails groups for loading based on: # # * The Rails environment; diff --git a/railties/lib/rails/application/bootstrap.rb b/railties/lib/rails/application/bootstrap.rb index 44ccef5cea..cebd9a8b52 100644 --- a/railties/lib/rails/application/bootstrap.rb +++ b/railties/lib/rails/application/bootstrap.rb @@ -49,8 +49,11 @@ module Rails ) logger end - Rails.logger.level = ActiveSupport::Logger.const_get(config.log_level.to_s.upcase) + + unless config.consider_all_requests_local + Rails.error.logger = Rails.logger + end end # Initialize cache early in the stack so railties can make use of it.