Merge pull request reidmorrison#192 from claracodes/fix-enqueue-messages

Fix enqueue messages for ActiveJob

Author: reidmorrison

lib/rails_semantic_logger/active_job/log_subscriber.rb

@@ -4,14 +4,44 @@ module RailsSemanticLogger
   module ActiveJob
     class LogSubscriber < ::ActiveSupport::LogSubscriber
       def enqueue(event)
-        log_with_formatter event: event do |fmt|
-          {message: "Enqueued #{fmt.job_info}"}
+        ex = event.payload[:exception_object]
+
+        if ex
+          log_with_formatter level: :error, event: event do |fmt|
+            {
+              message: "Failed enqueuing #{fmt.job_info} (#{ex.class} (#{ex.message})",
+              exception: ex
+            }
+          end
+        elsif event.payload[:aborted]
+          log_with_formatter level: :info, event: event do |fmt|
+            { message: "Failed enqueuing #{fmt.job_info}, a before_enqueue callback halted the enqueuing execution." }
+          end
+        else
+          log_with_formatter event: event do |fmt|
+            { message: "Enqueued #{fmt.job_info}" }
+          end
         end
       end
 
       def enqueue_at(event)
-        log_with_formatter event: event do |fmt|
-          {message: "Enqueued #{fmt.job_info} at #{fmt.scheduled_at}"}
+        ex = event.payload[:exception_object]
+
+        if ex
+          log_with_formatter level: :error, event: event do |fmt|
+            {
+              message: "Failed enqueuing #{fmt.job_info} (#{ex.class} (#{ex.message})",
+              exception: ex
+            }
+          end
+        elsif event.payload[:aborted]
+          log_with_formatter level: :info, event: event do |fmt|
+            { message: "Failed enqueuing #{fmt.job_info}, a before_enqueue callback halted the enqueuing execution." }
+          end
+        else
+          log_with_formatter event: event do |fmt|
+            {message: "Enqueued #{fmt.job_info} at #{fmt.scheduled_at}"}
+          end
         end
       end
 

test/active_job_test.rb

@@ -121,6 +121,145 @@ def id
         end
       end
 
+      describe "#enqueue with exception object" do
+        let(:event_name) { "enqueue.active_job" }
+
+        let(:payload) do
+          {
+            adapter:          ActiveJob::QueueAdapters::InlineAdapter.new,
+            job:              job,
+            exception_object: ArgumentError.new("error")
+          }
+        end
+
+        it "logs message" do
+          messages = semantic_logger_events do
+            subscriber.enqueue(event)
+          end
+          assert_equal 1, messages.count, messages
+
+          assert_semantic_logger_event(
+            messages[0],
+            level:            :error,
+            name:             "Rails",
+            message_includes: "Failed enqueuing ActiveJobTest::MyJob",
+            payload_includes: {
+              job_class:  "ActiveJobTest::MyJob",
+              queue:      "my_jobs",
+              event_name: "enqueue.active_job"
+            }
+          )
+          assert_includes messages[0].payload, :job_id
+
+          exception = messages[0].exception
+          assert exception.is_a?(ArgumentError)
+          assert_equal "error", exception.message
+        end
+      end
+
+      describe "#enqueue with throwing :abort" do
+        let(:event_name) { "enqueue.active_job" }
+
+        let(:payload) do
+          {
+            adapter: ActiveJob::QueueAdapters::InlineAdapter.new,
+            job:     job,
+            aborted: true
+          }
+        end
+
+        it "logs message" do
+          messages = semantic_logger_events do
+            subscriber.enqueue(event)
+          end
+          assert_equal 1, messages.count, messages
+
+          assert_semantic_logger_event(
+            messages[0],
+            level:            :info,
+            name:             "Rails",
+            message_includes: "Failed enqueuing ActiveJobTest::MyJob",
+            payload_includes: {
+              job_class:  "ActiveJobTest::MyJob",
+              queue:      "my_jobs",
+              event_name: "enqueue.active_job"
+            }
+          )
+          assert_match /Failed enqueuing .*, a before_enqueue callback halted the enqueuing execution/, messages[0].message
+          assert_includes messages[0].payload, :job_id
+        end
+      end
+
+      describe "#enqueue_at with exception object" do
+        let(:event_name) { "enqueue.active_job" }
+
+        let(:payload) do
+          {
+            adapter:          ActiveJob::QueueAdapters::InlineAdapter.new,
+            job:              job,
+            exception_object: ArgumentError.new("error")
+          }
+        end
+
+        it "logs message" do
+          messages = semantic_logger_events do
+            subscriber.enqueue_at(event)
+          end
+          assert_equal 1, messages.count, messages
+
+          assert_semantic_logger_event(
+            messages[0],
+            level:            :error,
+            name:             "Rails",
+            message_includes: "Failed enqueuing ActiveJobTest::MyJob",
+            payload_includes: {
+              job_class:  "ActiveJobTest::MyJob",
+              queue:      "my_jobs",
+              event_name: "enqueue.active_job"
+            }
+          )
+          assert_includes messages[0].payload, :job_id
+
+          exception = messages[0].exception
+          assert exception.is_a?(ArgumentError)
+          assert_equal "error", exception.message
+        end
+      end
+
+      describe "#enqueue_at with throwing :abort" do
+        let(:event_name) { "enqueue.active_job" }
+
+        let(:payload) do
+          {
+            adapter: ActiveJob::QueueAdapters::InlineAdapter.new,
+            job:     job,
+            aborted: true
+          }
+        end
+
+        it "logs message" do
+          messages = semantic_logger_events do
+            subscriber.enqueue_at(event)
+          end
+          assert_equal 1, messages.count, messages
+
+          assert_semantic_logger_event(
+            messages[0],
+            level:            :info,
+            name:             "Rails",
+            message_includes: "Failed enqueuing ActiveJobTest::MyJob",
+            payload_includes: {
+              job_class:  "ActiveJobTest::MyJob",
+              queue:      "my_jobs",
+              event_name: "enqueue.active_job"
+            }
+          )
+          assert_match /Failed enqueuing .*, a before_enqueue callback halted the enqueuing execution/, messages[0].message
+          assert_includes messages[0].payload, :job_id
+        end
+      end
+
+
       describe "ActiveJob::Logging::LogSubscriber::EventFormatter" do
         let(:formatter) do
           RailsSemanticLogger::ActiveJob::LogSubscriber::EventFormatter.new(event: event, log_duration: true)