Merge pull request #33171 from zvkemp/active-job-asn-wrap-enqueue

Wrap ActiveJob::Enqueue in evented ActiveSupport::Notification

3 files changed, 27 insertions, 6 deletions

diff --git a/activejob/CHANGELOG.md b/activejob/CHANGELOG.md
index 3ecbc2ff38..9e3c91fdfc 100644
--- a/activejob/CHANGELOG.md
+++ b/activejob/CHANGELOG.md
@@ -1,3 +1,7 @@
+*   Move `enqueue`/`enqueue_at` notifications to an around callback (was previously an after callback).
+
+    *Zach Kemp*
+
 *   Allow `queue` option to `assert_no_enqueued_jobs`.
 
     Example:
diff --git a/activejob/lib/active_job/logging.rb b/activejob/lib/active_job/logging.rb
index 3312857ac7..d17c772f30 100644
--- a/activejob/lib/active_job/logging.rb
+++ b/activejob/lib/active_job/logging.rb
@@ -27,13 +27,13 @@ module ActiveJob
         end
       end
 
-      after_enqueue do |job|
+      around_enqueue do |job, block|
         if job.scheduled_at
           ActiveSupport::Notifications.instrument "enqueue_at.active_job",
-            adapter: job.class.queue_adapter, job: job
+            adapter: job.class.queue_adapter, job: job, &block
         else
           ActiveSupport::Notifications.instrument "enqueue.active_job",
-            adapter: job.class.queue_adapter, job: job
+            adapter: job.class.queue_adapter, job: job, &block
         end
       end
     end
diff --git a/activejob/test/cases/logging_test.rb b/activejob/test/cases/logging_test.rb
index 1f8c4a5573..a1107a07fd 100644
--- a/activejob/test/cases/logging_test.rb
+++ b/activejob/test/cases/logging_test.rb
@@ -45,6 +45,14 @@ class LoggingTest < ActiveSupport::TestCase
     ActiveJob::Base.logger = logger
   end
 
+  def subscribed
+    [].tap do |events|
+      ActiveSupport::Notifications.subscribed(-> (*args) { events << args }, /enqueue.*\.active_job/) do
+        yield
+      end
+    end
+  end
+
   def test_uses_active_job_as_tag
     HelloJob.perform_later "Cristian"
     assert_match(/\[ActiveJob\]/, @logger.messages)
@@ -86,8 +94,11 @@ class LoggingTest < ActiveSupport::TestCase
   end
 
   def test_enqueue_job_logging
-    HelloJob.perform_later "Cristian"
+    events = subscribed { HelloJob.perform_later "Cristian" }
     assert_match(/Enqueued HelloJob \(Job ID: .*?\) to .*?:.*Cristian/, @logger.messages)
+    assert_equal(events.count, 1)
+    key, * = events.first
+    assert_equal(key, "enqueue.active_job")
   end
 
   def test_perform_job_logging
@@ -110,15 +121,21 @@ class LoggingTest < ActiveSupport::TestCase
   end
 
   def test_enqueue_at_job_logging
-    HelloJob.set(wait_until: 24.hours.from_now).perform_later "Cristian"
+    events = subscribed { HelloJob.set(wait_until: 24.hours.from_now).perform_later "Cristian" }
     assert_match(/Enqueued HelloJob \(Job ID: .*\) to .*? at.*Cristian/, @logger.messages)
+    assert_equal(events.count, 1)
+    key, * = events.first
+    assert_equal(key, "enqueue_at.active_job")
   rescue NotImplementedError
     skip
   end
 
   def test_enqueue_in_job_logging
-    HelloJob.set(wait: 2.seconds).perform_later "Cristian"
+    events = subscribed { HelloJob.set(wait: 2.seconds).perform_later "Cristian" }
     assert_match(/Enqueued HelloJob \(Job ID: .*\) to .*? at.*Cristian/, @logger.messages)
+    assert_equal(events.count, 1)
+    key, * = events.first
+    assert_equal(key, "enqueue_at.active_job")
   rescue NotImplementedError
     skip
   end