Merge pull request #40927 from islue/skip-logging-rescuable-exceptions

Skip logging rescuable exceptions

activejob/CHANGELOG.md

@@ -1,3 +1,7 @@
+*   Don't log rescuable exceptions defined with `rescue_from`.
+
+    *Hu Hailin*
+
 *   Allow `rescue_from` to rescue all exceptions.
 
     *Adrianna Chang*, *Étienne Barrié*

activejob/lib/active_job/base.rb

@@ -69,8 +69,8 @@ module ActiveJob #:nodoc:
     include Execution
     include Callbacks
     include Exceptions
-    include Logging
     include Instrumentation
+    include Logging
     include Timezones
     include Translation
 

activejob/lib/active_job/execution.rb

@@ -44,9 +44,7 @@ module ActiveJob
 
       deserialize_arguments_if_needed
 
-      run_callbacks :perform do
-        perform(*arguments)
-      end
+      _perform_job
     rescue Exception => exception
       rescue_with_handler(exception) || raise
     end
@@ -54,5 +52,12 @@ module ActiveJob
     def perform(*)
       fail NotImplementedError
     end
+
+    private
+      def _perform_job
+        run_callbacks :perform do
+          perform(*arguments)
+        end
+      end
   end
 end

activejob/lib/active_job/instrumentation.rb

@@ -8,14 +8,18 @@ module ActiveJob
       around_enqueue do |_, block|
         scheduled_at ? instrument(:enqueue_at, &block) : instrument(:enqueue, &block)
       end
+    end
 
-      around_perform do |_, block|
-        instrument :perform_start
-        instrument :perform, &block
-      end
+    def perform_now
+      instrument(:perform) { super }
     end
 
     private
+      def _perform_job
+        instrument(:perform_start)
+        super
+      end
+
       def instrument(operation, payload = {}, &block)
         enhanced_block = ->(event_payload) do
           value = block.call if block

activejob/lib/active_job/logging.rb

@@ -11,8 +11,11 @@ module ActiveJob
       cattr_accessor :logger, default: ActiveSupport::TaggedLogging.new(ActiveSupport::Logger.new(STDOUT))
       class_attribute :log_arguments, instance_accessor: false, default: true
 
-      around_enqueue { |_, block| tag_logger(&block) }
-      around_perform { |job, block| tag_logger(job.class.name, job.job_id, &block) }
+      around_enqueue(prepend: true) { |_, block| tag_logger(&block) }
+    end
+
+    def perform_now
+      tag_logger(self.class.name, self.job_id) { super }
     end
 
     private

activejob/test/cases/logging_test.rb

@@ -260,6 +260,12 @@ class LoggingTest < ActiveSupport::TestCase
     end
   end
 
+  def test_job_no_error_logging_on_rescuable_job
+    perform_enqueued_jobs { RescueJob.perform_later "david" }
+    assert_match(/Performing RescueJob \(Job ID: .*?\) from .*? with arguments:.*david/, @logger.messages)
+    assert_no_match(/Error performing RescueJob \(Job ID: .*?\) from .*? in .*ms: ArgumentError \(Hair too good\):\n.*\brescue_job\.rb:\d+:in `perform'/, @logger.messages)
+  end
+
   def test_enqueue_retry_logging
     perform_enqueued_jobs do
       RetryJob.perform_later "DefaultsError", 2