Log when rescue_from handles an exception

In development when a `before_action` renders or redirects this error
message appears on the logs:

> Filter chain halted as :before_action rendered or redirected

I find this message very helpful. However, if a before_action raises an
error that is handled by a rescue_from block, nothing is logged
indicating an error occurred.

This PR adds a log message indicating an exception was rescued, and
displays where it was originally raised. For example:

> rescue_from handled BaseController::YourError (Oh no!) -
>   app/controllers/home_controller.rb:9:in 'HomeController#authenticate'

Co-Authored-By: Jean Boussier <[email protected]>

Author: swebb

actionpack/CHANGELOG.md

@@ -1,3 +1,7 @@
+*   Produce a log when `rescue_from` is invoked.
+
+    *Steven Webb*, *Jean Boussier*
+
 *   Allow hosts redirects from `hosts` Rails configuration
 
     ```ruby

actionpack/lib/action_controller/log_subscriber.rb

@@ -49,6 +49,13 @@ def halted_callback(event)
     end
     subscribe_log_level :halted_callback, :info
 
+    # Manually subscribed below
+    def rescue_from_callback(event)
+      exception = event.payload[:exception]
+      info { "rescue_from handled #{exception.class} (#{exception.message}) - #{exception.backtrace.first.delete_prefix("#{Rails.root}/")}" }
+    end
+    subscribe_log_level :rescue_from_callback, :info
+
     def send_file(event)
       info { "Sent file #{event.payload[:path]} (#{event.duration.round(1)}ms)" }
     end

actionpack/test/controller/log_subscriber_test.rb

@@ -77,11 +77,11 @@ def with_throw
     end
 
     def with_exception
-      raise Exception
+      raise Exception, "Oopsie"
     end
 
     def with_rescued_exception
-      raise SpecialException
+      raise SpecialException, "Oops"
     end
 
     def with_action_not_found
@@ -154,6 +154,13 @@ def test_halted_callback
     assert_equal "Filter chain halted as :redirector rendered or redirected", logs.third
   end
 
+  def test_rescue_from_callback
+    get :with_rescued_exception
+    wait
+    assert_equal 3, logs.size
+    assert_match "rescue_from handled Another::LogSubscribersController::SpecialException", logs.second
+  end
+
   def test_process_action
     get :show
     wait
@@ -406,7 +413,7 @@ def test_process_action_with_rescued_exception_includes_http_status_code
     get :with_rescued_exception
     wait
 
-    assert_equal 2, logs.size
+    assert_equal 3, logs.size
     assert_match(/Completed 406/, logs.last)
   end
 

activesupport/lib/active_support/rescuable.rb

@@ -92,6 +92,7 @@ def rescue_with_handler(exception, object: self, visited_exceptions: [])
 
         if handler = handler_for_rescue(exception, object: object)
           handler.call exception
+          ActiveSupport::Notifications.instrument("rescue_from_callback.action_controller", exception: exception)
           exception
         elsif exception
           if visited_exceptions.include?(exception.cause)