From ca61139faeeae380582dbf14d8bcfcb37f602bf7 Mon Sep 17 00:00:00 2001
From: Edouard CHIN <edouard.chin@shopify.com>
Date: Sat, 28 Dec 2019 19:12:33 +0100
Subject: [PATCH] Fix wrong logging message in AJ in case a job returns a
 falsey value:

- I made a change in 0d3aec49695 to output a log if a job was aborted
  in a before callbacks. I didn't take in consideration that a job
  could return a falsy value and thus it would wrongly log
  that the job was aborted.

  This fixes the problem by checking if the callback chain was halted
  rather than the return value of the job.
---
 activejob/lib/active_job/instrumentation.rb | 12 +++++++--
 activejob/test/cases/logging_test.rb        | 29 +++++++++++++++++++++
 2 files changed, 39 insertions(+), 2 deletions(-)

diff --git a/activejob/lib/active_job/instrumentation.rb b/activejob/lib/active_job/instrumentation.rb
index 1534da3561..b94c5af99b 100644
--- a/activejob/lib/active_job/instrumentation.rb
+++ b/activejob/lib/active_job/instrumentation.rb
@@ -18,12 +18,20 @@ module ActiveJob
     private
       def instrument(operation, payload = {}, &block)
         enhanced_block = ->(event_payload) do
-          aborted = !block.call if block
-          event_payload[:aborted] = true if aborted
+          block.call if block
+          if defined?(@_halted_callback_hook_called) && @_halted_callback_hook_called
+            event_payload[:aborted] = true
+            @_halted_callback_hook_called = nil
+          end
         end
 
         ActiveSupport::Notifications.instrument \
           "#{operation}.active_job", payload.merge(adapter: queue_adapter, job: self), &enhanced_block
       end
+
+      def halted_callback_hook(_)
+        super
+        @_halted_callback_hook_called = true
+      end
   end
 end
diff --git a/activejob/test/cases/logging_test.rb b/activejob/test/cases/logging_test.rb
index f21df62e2e..d38c640f43 100644
--- a/activejob/test/cases/logging_test.rb
+++ b/activejob/test/cases/logging_test.rb
@@ -150,6 +150,35 @@ class LoggingTest < ActiveSupport::TestCase
     assert_match(/Error performing AbortBeforeEnqueueJob.* a before_perform callback halted/, @logger.messages)
   end
 
+  def test_perform_job_doesnt_log_error_when_job_returns_falsy_value
+    job = Class.new(ActiveJob::Base) do
+      def perform
+        nil
+      end
+    end
+
+    subscribed { job.perform_now }
+    assert_no_match(/Error performing AbortBeforeEnqueueJob.* a before_perform callback halted/, @logger.messages)
+  end
+
+  def test_perform_job_doesnt_log_error_when_job_is_performed_multiple_times_and_fail_the_first_time
+    job = Class.new(ActiveJob::Base) do
+      before_perform do
+        throw(:abort) if arguments[0].pop == :abort
+      end
+
+      def perform(_)
+      end
+    end.new([:dont_abort, :abort])
+
+    subscribed do
+      job.perform_now
+      job.perform_now
+    end
+
+    assert_equal(1, @logger.messages.scan(/a before_perform callback halted the job execution/).size)
+  end
+
   def test_perform_disabled_job_logging
     perform_enqueued_jobs do
       DisableLogJob.perform_later "Dummy"