Skip logging backtrace when exception is in rescue_responses

Closes rails#9343

Co-authored-by: Mike Dalessio <[email protected]>

Author: alaz

actionpack/CHANGELOG.md

@@ -1,3 +1,13 @@
+*   Configuration setting to skip logging an uncaught exception backtrace when the exception is
+    present in `rescued_responses`.
+
+    It may be too noisy to get all backtraces logged for applications that manage uncaught
+    exceptions via `rescued_responses` and `exceptions_app`.
+    `config.action_dispatch.log_rescued_responses` (defaults to `true`) can be set to `false` in
+    this case, so that only exceptions not found in `rescued_responses` will be logged.
+
+    *Alexander Azarov*, *Mike Dalessio*
+
 *   Ignore file fixtures on `db:fixtures:load`
 
     *Kevin Sjöberg*

actionpack/lib/action_dispatch/middleware/debug_exceptions.rb

@@ -10,6 +10,7 @@ module ActionDispatch
   # This middleware is responsible for logging exceptions and
   # showing a debugging page in case the request is local.
   class DebugExceptions
+    cattr_accessor :log_rescued_responses, instance_accessor: false, default: true
     cattr_reader :interceptors, instance_accessor: false, default: []
 
     def self.register_interceptor(object = nil, &block)
@@ -135,6 +136,7 @@ def log_error(request, wrapper)
         logger = logger(request)
 
         return unless logger
+        return if !log_rescued_responses?(request) && wrapper.rescue_response?
 
         exception = wrapper.exception
         trace = wrapper.exception_trace
@@ -176,5 +178,10 @@ def routes_inspector(exception)
       def api_request?(content_type)
         @response_format == :api && !content_type.html?
       end
+
+      def log_rescued_responses?(request)
+        per_request = request.get_header("action_dispatch.log_rescued_responses")
+        per_request.nil? ? @@log_rescued_responses : per_request
+      end
   end
 end

actionpack/lib/action_dispatch/middleware/exception_wrapper.rb

@@ -118,6 +118,10 @@ def self.status_code_for_exception(class_name)
       Rack::Utils.status_code(@@rescue_responses[class_name])
     end
 
+    def rescue_response?
+      @@rescue_responses.key?(exception.class.name)
+    end
+
     def source_extracts
       backtrace.map do |trace|
         file, line_number = extract_file_and_line_number(trace)

actionpack/lib/action_dispatch/railtie.rb

@@ -25,6 +25,7 @@ class Railtie < Rails::Railtie # :nodoc:
     config.action_dispatch.perform_deep_munge = true
     config.action_dispatch.request_id_header = "X-Request-Id"
     config.action_dispatch.return_only_request_media_type_on_content_type = true
+    config.action_dispatch.log_rescued_responses = true
 
     config.action_dispatch.default_headers = {
       "X-Frame-Options" => "SAMEORIGIN",
@@ -47,6 +48,7 @@ class Railtie < Rails::Railtie # :nodoc:
         self.ignore_accept_header = app.config.action_dispatch.ignore_accept_header
         self.return_only_media_type_on_content_type = app.config.action_dispatch.return_only_request_media_type_on_content_type
         ActionDispatch::Request::Utils.perform_deep_munge = app.config.action_dispatch.perform_deep_munge
+        ActionDispatch::DebugExceptions.log_rescued_responses = app.config.action_dispatch.log_rescued_responses
       end
 
       ActiveSupport.on_load(:action_dispatch_response) do

actionpack/test/dispatch/debug_exceptions_test.rb

@@ -515,9 +515,9 @@ def call(env)
     backtrace_cleaner = ActiveSupport::BacktraceCleaner.new
     backtrace_cleaner.add_silencer { true }
 
-    env = { "action_dispatch.show_exceptions" => true,
-           "action_dispatch.logger" => Logger.new(output),
-           "action_dispatch.backtrace_cleaner" => backtrace_cleaner }
+    env = { "action_dispatch.show_exceptions"   => true,
+            "action_dispatch.logger"            => Logger.new(output),
+            "action_dispatch.backtrace_cleaner" => backtrace_cleaner }
 
     get "/", headers: env
     assert_operator((output.rewind && output.read).lines.count, :>, 10)
@@ -544,7 +544,7 @@ def call(env)
     assert_equal 3, log.lines.count
   end
 
-  test "doesn't log the framework backtrace when error type is a invalid mine type" do
+  test "doesn't log the framework backtrace when error type is a invalid mime type" do
     @app = ProductionApp
 
     output = StringIO.new
@@ -566,6 +566,20 @@ def call(env)
     assert_equal 3, log.lines.count
   end
 
+  test "skips logging when rescued" do
+    @app = DevelopmentApp
+
+    output = StringIO.new
+
+    env = { "action_dispatch.show_exceptions"       => true,
+            "action_dispatch.logger"                => Logger.new(output),
+            "action_dispatch.log_rescued_responses" => false }
+
+    get "/parameter_missing", headers: env
+    assert_response 400
+    assert_empty (output.rewind && output.read).lines
+  end
+
   test "display backtrace when error type is SyntaxError" do
     @app = DevelopmentApp
 

actionpack/test/dispatch/exception_wrapper_test.rb

@@ -66,6 +66,18 @@ def backtrace
       assert_equal 400, wrapper.status_code
     end
 
+    test "#rescue_response? returns false for an exception that's not in rescue_responses" do
+      exception = RuntimeError.new
+      wrapper = ExceptionWrapper.new(@cleaner, exception)
+      assert_equal false, wrapper.rescue_response?
+    end
+
+    test "#rescue_response? returns true for an exception that is in rescue_responses" do
+      exception = ActionController::RoutingError.new("")
+      wrapper = ExceptionWrapper.new(@cleaner, exception)
+      assert_equal true, wrapper.rescue_response?
+    end
+
     test "#application_trace cannot be nil" do
       nil_backtrace_wrapper = ExceptionWrapper.new(@cleaner, BadlyDefinedError.new)
       nil_cleaner_wrapper = ExceptionWrapper.new(nil, BadlyDefinedError.new)

guides/source/configuring.md

@@ -689,6 +689,9 @@ Defaults to `'signed cookie'`.
   in the `ActionDispatch::SSL` middleware. Defaults to `308` as defined in
   https://tools.ietf.org/html/rfc7538.
 
+* `config.action_dispatch.log_rescued_responses` enables logging those unhandled
+  exceptions configured in `rescue_responses`. It defaults to `true`.
+
 * `ActionDispatch::Callbacks.before` takes a block of code to run before the request.
 
 * `ActionDispatch::Callbacks.after` takes a block of code to run after the request.

railties/test/application/configuration_test.rb

@@ -3159,6 +3159,22 @@ class MyLogger < ::Logger
       assert_equal false, ActionDispatch::Request.return_only_media_type_on_content_type
     end
 
+    test "ActionDispatch::DebugExceptions.log_rescued_responses is true by default" do
+      app "development"
+
+      assert_equal true, ActionDispatch::DebugExceptions.log_rescued_responses
+    end
+
+    test "ActionDispatch::DebugExceptions.log_rescued_responses can be configured" do
+      add_to_config <<-RUBY
+        config.action_dispatch.log_rescued_responses = false
+      RUBY
+
+      app "development"
+
+      assert_equal false, ActionDispatch::DebugExceptions.log_rescued_responses
+    end
+
     test "logs a warning when running SQLite3 in production" do
       restore_sqlite3_warning
       app_file "config/initializers/active_record.rb", <<~RUBY