Swap Active Job log subscriber safely (reidmorrison#97)

Author: prikha

lib/rails_semantic_logger.rb

@@ -9,6 +9,9 @@ module ActionController
   module ActionView
     autoload :LogSubscriber, 'rails_semantic_logger/action_view/log_subscriber'
   end
+  module ActiveJob
+    autoload :LogSubscriber, 'rails_semantic_logger/active_job/log_subscriber'
+  end
   module ActiveRecord
     autoload :LogSubscriber, 'rails_semantic_logger/active_record/log_subscriber'
   end

lib/rails_semantic_logger/active_job/log_subscriber.rb

@@ -0,0 +1,117 @@
+require 'active_job'
+
+module RailsSemanticLogger
+  module ActiveJob
+    class LogSubscriber < ::ActiveSupport::LogSubscriber
+      def enqueue(event)
+        log_with_formatter event: event do |fmt|
+          "Enqueued #{fmt.job_info}"
+        end
+      end
+
+      def enqueue_at(event)
+        log_with_formatter event: event do |fmt|
+          "Enqueued #{fmt.job_info} at #{fmt.scheduled_at}"
+        end
+      end
+
+      def perform_start(event)
+        log_with_formatter event: event do |fmt|
+          "Performing #{fmt.job_info}"
+        end
+      end
+
+      def perform(event)
+        ex = event.payload[:exception_object]
+        if ex
+          logger.error ex
+        else
+          log_with_formatter event: event, log_duration: true do |fmt|
+            "Performed #{fmt.job_info} in #{event.duration.round(2)}ms"
+          end
+        end
+      end
+
+      private
+
+      class EventFormatter
+        def initialize(event:, log_duration: false)
+          @event = event
+          @log_duration = log_duration
+        end
+
+        def job_info
+          "#{job.class.name} (Job ID: #{job.job_id}) to #{queue_name}"
+        end
+
+        def payload
+          {}.tap do |h|
+            h[:event_name]      = event.name
+            h[:adapter]         = adapter_name
+            h[:queue]           = job.queue_name
+            h[:job_class]       = job.class.name
+            h[:job_id]          = job.job_id
+            h[:provider_job_id] = job.try(:provider_job_id) # Not available in Rails 4.2
+            h[:duration]        = event.duration.round(2) if log_duration?
+            h[:arguments]       = formatted_args
+          end
+        end
+
+        def queue_name
+          adapter_name + "(#{job.queue_name})"
+        end
+
+        def scheduled_at
+          Time.at(event.payload[:job].scheduled_at).utc
+        end
+
+        private
+
+        attr_reader :event
+
+        def job
+          event.payload[:job]
+        end
+
+        def adapter_name
+          event.payload[:adapter].class.name.demodulize.remove('Adapter')
+        end
+
+        def formatted_args
+          JSON.pretty_generate(job.arguments.map { |arg| format(arg) })
+        end
+
+        def format(arg)
+          case arg
+          when Hash
+            arg.transform_values { |value| format(value) }
+          when Array
+            arg.map { |value| format(value) }
+          when GlobalID::Identification
+            begin
+              arg.to_global_id
+            rescue StandardError
+              arg
+            end
+          else
+            arg
+          end
+        end
+
+        def log_duration?
+          @log_duration
+        end
+      end
+
+      def log_with_formatter(**kw_args)
+        fmt = EventFormatter.new(**kw_args)
+        msg = yield fmt
+        logger.info msg, fmt.payload
+      end
+
+      def logger
+        ::ActiveJob::Base.logger
+      end
+    end
+  end
+end

lib/rails_semantic_logger/engine.rb

@@ -137,6 +137,15 @@ class Engine < ::Rails::Engine
       require('rails_semantic_logger/extensions/active_model_serializers/logging') if defined?(ActiveModelSerializers)
 
       if config.rails_semantic_logger.semantic
+        # Active Job
+        if defined?(::ActiveJob)
+          RailsSemanticLogger.swap_subscriber(
+            ::ActiveJob::Logging::LogSubscriber,
+            RailsSemanticLogger::ActiveJob::LogSubscriber,
+            :active_job
+          )
+        end
+
         # Active Record
         if defined?(::ActiveRecord)
           require 'active_record/log_subscriber'

lib/rails_semantic_logger/extensions/active_job/logging.rb

@@ -10,126 +10,6 @@ module Logging
     def tag_logger(*tags, &block)
       logger.tagged(*tags, &block)
     end
-
-    class LogSubscriber < ActiveSupport::LogSubscriber
-      def enqueue(event)
-        log_with_formatter event: event do |fmt|
-          "Enqueued #{fmt.job_info}"
-        end
-      end
-
-      def enqueue_at(event)
-        log_with_formatter event: event do |fmt|
-          "Enqueued #{fmt.job_info} at #{fmt.scheduled_at}"
-        end
-      end
-
-      def perform_start(event)
-        log_with_formatter event: event do |fmt|
-          "Performing #{fmt.job_info}"
-        end
-      end
-
-      def perform(event)
-        ex = event.payload[:exception_object]
-        if ex
-          logger.error ex
-        else
-          log_with_formatter event: event, log_duration: true do |fmt|
-            "Performed #{fmt.job_info} in #{event.duration.round(2)}ms"
-          end
-        end
-      end
-
-      private
-
-      class EventFormatter
-        def initialize(event:, log_duration: false)
-          @event = event
-          @log_duration = log_duration
-        end
-
-        def job_info
-          "#{job.class.name} (Job ID: #{job.job_id}) to #{queue_name}"
-        end
-
-        def payload
-          {}.tap do |h|
-            h[:event_name]      = event.name
-            h[:adapter]         = adapter_name
-            h[:queue]           = job.queue_name
-            h[:job_class]       = job.class.name
-            h[:job_id]          = job.job_id
-            h[:provider_job_id] = job.try(:provider_job_id) # Not available in Rails 4.2
-            h[:duration]        = event.duration.round(2) if log_duration?
-            h[:arguments]       = formatted_args
-          end
-        end
-
-        def queue_name
-          adapter_name + "(#{job.queue_name})"
-        end
-
-        def scheduled_at
-          Time.at(event.payload[:job].scheduled_at).utc
-        end
-
-        private
-
-        attr_reader :event
-
-        def job
-          event.payload[:job]
-        end
-
-        def adapter_name
-          event.payload[:adapter].class.name.demodulize.remove('Adapter')
-        end
-
-        def formatted_args
-          JSON.pretty_generate(job.arguments.map { |arg| format(arg) })
-        end
-
-        def format(arg)
-          case arg
-          when Hash
-            arg.transform_values { |value| format(value) }
-          when Array
-            arg.map { |value| format(value) }
-          when GlobalID::Identification
-            begin
-              arg.to_global_id
-            rescue StandardError
-              arg
-            end
-          else
-            arg
-          end
-        end
-
-        def log_duration?
-          @log_duration
-        end
-      end
-
-      def log_with_formatter(**kw_args)
-        fmt = EventFormatter.new(**kw_args)
-        msg = yield fmt
-        logger.info msg, fmt.payload
-      end
-
-      def logger
-        ActiveJob::Base.logger
-      end
-    end
   end
 end
 
-if defined?(ActiveSupport::Notifications)
-  ActiveSupport::Notifications.unsubscribe('perform_start.active_job')
-  ActiveSupport::Notifications.unsubscribe('perform.active_job')
-  ActiveSupport::Notifications.unsubscribe('enqueue_at.active_job')
-  ActiveSupport::Notifications.unsubscribe('enqueue.active_job')
-
-  ActiveJob::Logging::LogSubscriber.attach_to :active_job
-end

test/active_job_test.rb

@@ -39,7 +39,7 @@ def id
         skip 'Older rails does not support ActiveSupport::Notification' unless defined?(ActiveSupport::Notifications)
       end
 
-      let(:subscriber) { ActiveJob::Logging::LogSubscriber.new }
+      let(:subscriber) { RailsSemanticLogger::ActiveJob::LogSubscriber.new }
 
       let(:event) do
         ActiveSupport::Notifications::Event.new 'enqueue.active_job',
@@ -67,7 +67,7 @@ def id
 
       describe 'ActiveJob::Logging::LogSubscriber::EventFormatter' do
         let(:formatter) do
-          ActiveJob::Logging::LogSubscriber::EventFormatter.new(event: event, log_duration: true)
+          RailsSemanticLogger::ActiveJob::LogSubscriber::EventFormatter.new(event: event, log_duration: true)
         end
 
         let(:event) do