Merge pull request #222 from reidmorrison/sidekiq

Add support for Sidekiq

.github/workflows/ci.yml

@@ -26,7 +26,7 @@ jobs:
 
           - rails: "7.0"
             ruby: "3.1"
-          - rails: "7.0"
+          - rails: "7.0b"
             ruby: "3.2"
 
           - rails: "7.1"
@@ -36,6 +36,9 @@ jobs:
           - rails: "7.1"
             ruby: "3.2"
 
+          - rails: "7.2"
+            ruby: "3.3"
+
     env:
       BUNDLE_GEMFILE: gemfiles/rails_${{ matrix.rails }}.gemfile
       DISPLAY: ":99.0"

.gitignore

@@ -15,3 +15,4 @@ Gemfile.lock
 .rakeTasks
 TODO.md
 
+.tool-versions

Appraisals

@@ -1,24 +1,40 @@
 appraise "rails_6.0" do
   gem "rails", "~> 6.0.0"
-  gem "sqlite3", "~> 1.4.0", platform: :ruby
+  gem "sidekiq", "~> 4.2"
+  gem "sqlite3", "~> 1.4"
 end
 
 appraise "rails_6.1" do
   gem "rails", "~> 6.1.0"
-  gem "sqlite3", "~> 1.4.0", platform: :ruby
+  gem "sidekiq", "~> 5.2"
+  gem "sqlite3", "~> 1.4"
 end
 
 appraise "rails_7.0" do
   gem "rails", "~> 7.0.0"
-  gem "sqlite3", "~> 1.4.0", platform: :ruby
+  gem "sidekiq", "~> 6.2.0"
+  gem "sqlite3", "~> 1.4"
+end
+
+appraise "rails_7.0b" do
+  gem "rails", "~> 7.0.0"
+  gem "sidekiq", "~> 6.5"
+  gem "sqlite3", "~> 1.4"
 end
 
 appraise "rails_7.1.1" do
   gem "rails", "7.1.1"
-  gem "sqlite3", "~> 1.4.0", platform: :ruby
+  gem "sidekiq", "~> 7.0.9"
+  gem "sqlite3", "~> 1.4"
 end
 
 appraise "rails_7.1" do
   gem "rails", "~> 7.1.0"
-  gem "sqlite3", "~> 1.4.0", platform: :ruby
+  gem "sidekiq", "~> 7.1.6"
+  gem "sqlite3", "~> 1.4"
+end
+
+appraise "rails_7.2" do
+  gem "rails", "~> 7.2.0.beta2"
+  gem "sidekiq", "~> 7.2.4"
 end

Gemfile

@@ -12,7 +12,8 @@ gem "minitest-rails"
 gem "rake"
 gem "sprockets", "< 4.0"
 
-gem "rails", "~> 7.1.0"
-gem "sqlite3", "~> 1.4.0", platform: :ruby
+gem "rails", "~> 7.2.0.beta2"
+gem "sidekiq", "~> 7.2.4"
+gem "sqlite3"
 
 gem "rubocop"

gemfiles/rails_6.0.gemfile

@@ -11,7 +11,8 @@ gem "minitest-rails"
 gem "rake"
 gem "sprockets", "< 4.0"
 gem "rails", "~> 6.0.0"
-gem "sqlite3", "~> 1.4.0", platform: :ruby
+gem "sidekiq", "~> 4.2"
+gem "sqlite3", "~> 1.4"
 gem "rubocop"
 
 gemspec path: "../"

gemfiles/rails_6.1.gemfile

@@ -11,7 +11,8 @@ gem "minitest-rails"
 gem "rake"
 gem "sprockets", "< 4.0"
 gem "rails", "~> 6.1.0"
-gem "sqlite3", "~> 1.4.0", platform: :ruby
+gem "sidekiq", "~> 5.2"
+gem "sqlite3", "~> 1.4"
 gem "rubocop"
 
 gemspec path: "../"

gemfiles/rails_7.0.gemfile

@@ -11,7 +11,8 @@ gem "minitest-rails"
 gem "rake"
 gem "sprockets", "< 4.0"
 gem "rails", "~> 7.0.0"
-gem "sqlite3", "~> 1.4.0", platform: :ruby
+gem "sidekiq", "~> 6.2.0"
+gem "sqlite3", "~> 1.4"
 gem "rubocop"
 
 gemspec path: "../"

gemfiles/rails_7.0b.gemfile

@@ -0,0 +1,18 @@
+# This file was generated by Appraisal
+
+source "https://rubygems.org"
+
+gem "appraisal"
+gem "puma"
+gem "active_model_serializers"
+gem "amazing_print"
+gem "minitest"
+gem "minitest-rails"
+gem "rake"
+gem "sprockets", "< 4.0"
+gem "rails", "~> 7.0.0"
+gem "sidekiq", "~> 6.5"
+gem "sqlite3", "~> 1.4"
+gem "rubocop"
+
+gemspec path: "../"

gemfiles/rails_7.1.1.gemfile

@@ -11,7 +11,8 @@ gem "minitest-rails"
 gem "rake"
 gem "sprockets", "< 4.0"
 gem "rails", "7.1.1"
-gem "sqlite3", "~> 1.4.0", platform: :ruby
+gem "sidekiq", "~> 7.0.9"
+gem "sqlite3", "~> 1.4"
 gem "rubocop"
 
 gemspec path: "../"

gemfiles/rails_7.1.gemfile

@@ -11,7 +11,8 @@ gem "minitest-rails"
 gem "rake"
 gem "sprockets", "< 4.0"
 gem "rails", "~> 7.1.0"
-gem "sqlite3", "~> 1.4.0", platform: :ruby
+gem "sidekiq", "~> 7.1.6"
+gem "sqlite3", "~> 1.4"
 gem "rubocop"
 
 gemspec path: "../"

gemfiles/rails_7.2.gemfile

@@ -0,0 +1,18 @@
+# This file was generated by Appraisal
+
+source "https://rubygems.org"
+
+gem "appraisal"
+gem "puma"
+gem "active_model_serializers"
+gem "amazing_print"
+gem "minitest"
+gem "minitest-rails"
+gem "rake"
+gem "sprockets", "< 4.0"
+gem "rails", "~> 7.2.0.beta2"
+gem "sidekiq", "~> 7.2.4"
+gem "sqlite3"
+gem "rubocop"
+
+gemspec path: "../"

lib/rails_semantic_logger/engine.rb

@@ -224,6 +224,8 @@ class Engine < ::Rails::Engine
             :action_mailer
           )
         end
+
+        require("rails_semantic_logger/extensions/sidekiq/sidekiq") if defined?(::Sidekiq)
       end
 
       #

lib/rails_semantic_logger/extensions/sidekiq/sidekiq.rb

@@ -0,0 +1,211 @@
+# Sidekiq patches
+#
+# To re-enable stdout logging for sidekiq server processes, add the following snippet to config/initializers/sidekiq.rb:
+#   Sidekiq.configure_server do |config|
+#     SemanticLogger.add_appender(io: $stdout, level: :debug, formatter: :color)
+#   end
+if Sidekiq::VERSION.to_i == 4
+  require "sidekiq/exception_handler"
+  require "sidekiq/logging"
+  require "sidekiq/middleware/server/logging"
+  require "sidekiq/processor"
+  require "sidekiq/worker"
+elsif Sidekiq::VERSION.to_i == 5
+  require "sidekiq/exception_handler"
+  require "sidekiq/job_logger"
+  require "sidekiq/logging"
+  require "sidekiq/worker"
+elsif Sidekiq::VERSION.to_i == 6 && Sidekiq::VERSION.to_f < 6.5
+  require "sidekiq/exception_handler"
+  require "sidekiq/job_logger"
+  require "sidekiq/worker"
+elsif Sidekiq::VERSION.to_i == 6
+  require "sidekiq/job_logger"
+  require "sidekiq/worker"
+else
+  require "sidekiq/config"
+  require "sidekiq/job_logger"
+  require "sidekiq/job"
+end
+
+module Sidekiq
+  # Sidekiq > v4
+  if defined?(::Sidekiq::JobLogger)
+    # Let Semantic Logger handle duration logging
+    class JobLogger
+      def call(item, queue)
+        klass  = item["wrapped"] || item["class"]
+        metric = "Sidekiq/#{klass}/perform" if klass
+        logger = klass ? SemanticLogger[klass] : Sidekiq.logger
+        logger.info("Start #perform")
+        logger.measure_info(
+          "Completed #perform",
+          on_exception_level: :error,
+          log_exception:      :full,
+          metric:             metric
+        ) do
+          yield
+        end
+      end
+
+      def prepare(job_hash, &block)
+        level = job_hash["log_level"]
+        if level
+          SemanticLogger.silence(level) do
+            SemanticLogger.tagged(job_hash_context(job_hash), &block)
+          end
+        else
+          SemanticLogger.tagged(job_hash_context(job_hash), &block)
+        end
+      end
+
+      def job_hash_context(job_hash)
+        h        = {
+          class: job_hash["display_class"] || job_hash["wrapped"] || job_hash["class"],
+          jid:   job_hash["jid"]
+        }
+        h[:bid]  = job_hash["bid"] if job_hash["bid"]
+        h[:tags] = job_hash["tags"] if job_hash["tags"]
+        h
+      end
+    end
+  end
+
+  # Sidekiq <= v6
+  if defined?(::Sidekiq::Logging)
+    # Replace Sidekiq logging context
+    module Logging
+      def self.with_context(msg, &block)
+        SemanticLogger.tagged(msg, &block)
+      end
+
+      def self.job_hash_context(job_hash)
+        klass       = job_hash["wrapped"] || job_hash["class"]
+        event       = { class: klass, jid: job_hash["jid"] }
+        event[:bid] = job_hash["bid"] if job_hash["bid"]
+        event
+      end
+    end
+  end
+
+  # Exception is already logged by Semantic Logger during the perform call
+  # Sidekiq <= v6.5
+  if defined?(::Sidekiq::ExceptionHandler)
+    module ExceptionHandler
+      class Logger
+        def call(ex, ctx)
+          unless ctx.empty?
+            job_hash = ctx[:job] || {}
+            klass = job_hash["display_class"] || job_hash["wrapped"] || job_hash["class"]
+            logger = klass ? SemanticLogger[klass] : Sidekiq.logger
+            ctx[:context] ? logger.warn(ctx[:context], ctx) : logger.warn(ctx)
+          end
+        end
+      end
+    end
+  # Sidekiq >= v7
+  elsif defined?(::Sidekiq::Config)
+    class Config
+      remove_const :ERROR_HANDLER
+
+      ERROR_HANDLER = ->(ex, ctx, cfg = Sidekiq.default_configuration) {
+        unless ctx.empty?
+          job_hash = ctx[:job] || {}
+          klass = job_hash["display_class"] || job_hash["wrapped"] || job_hash["class"]
+          logger = klass ? SemanticLogger[klass] : Sidekiq.logger
+          ctx[:context] ? logger.warn(ctx[:context], ctx) : logger.warn(ctx)
+        end
+      }
+    end
+  else
+    # Sidekiq >= 6.5
+    # TODO: Not taking effect. See test/sidekiq_test.rb
+    def self.default_error_handler(ex, ctx)
+      binding.irb
+      unless ctx.empty?
+        job_hash = ctx[:job] || {}
+        klass = job_hash["display_class"] || job_hash["wrapped"] || job_hash["class"]
+        logger = klass ? SemanticLogger[klass] : Sidekiq.logger
+        ctx[:context] ? logger.warn(ctx[:context], ctx) : logger.warn(ctx)
+      end
+    end
+  end
+
+  # Logging within each worker should use its own logger
+  if Sidekiq::VERSION.to_i == 4
+    module Worker
+      def self.included(base)
+        raise ArgumentError, "You cannot include Sidekiq::Worker in an ActiveJob: #{base.name}" if base.ancestors.any? { |c| c.name == "ActiveJob::Base" }
+
+        base.extend(ClassMethods)
+        base.include(SemanticLogger::Loggable)
+        base.class_attribute :sidekiq_options_hash
+        base.class_attribute :sidekiq_retry_in_block
+        base.class_attribute :sidekiq_retries_exhausted_block
+      end
+    end
+  elsif Sidekiq::VERSION.to_i == 5
+    module Worker
+      def self.included(base)
+        raise ArgumentError, "You cannot include Sidekiq::Worker in an ActiveJob: #{base.name}" if base.ancestors.any? { |c| c.name == "ActiveJob::Base" }
+
+        base.extend(ClassMethods)
+        base.include(SemanticLogger::Loggable)
+        base.sidekiq_class_attribute :sidekiq_options_hash
+        base.sidekiq_class_attribute :sidekiq_retry_in_block
+        base.sidekiq_class_attribute :sidekiq_retries_exhausted_block
+      end
+    end
+  elsif Sidekiq::VERSION.to_i == 6
+    module Worker
+      def self.included(base)
+        raise ArgumentError, "Sidekiq::Worker cannot be included in an ActiveJob: #{base.name}" if base.ancestors.any? { |c| c.name == "ActiveJob::Base" }
+
+        base.include(Options)
+        base.extend(ClassMethods)
+        base.include(SemanticLogger::Loggable)
+      end
+    end
+  else
+    module Job
+      def self.included(base)
+        raise ArgumentError, "Sidekiq::Job cannot be included in an ActiveJob: #{base.name}" if base.ancestors.any? { |c| c.name == "ActiveJob::Base" }
+
+        base.include(Options)
+        base.extend(ClassMethods)
+        base.include(SemanticLogger::Loggable)
+      end
+    end
+  end
+
+  if Sidekiq::VERSION.to_i == 4
+    # Convert string to machine readable format
+    class Processor
+      def log_context(job_hash)
+        klass       = job_hash["wrapped"] || job_hash["class"]
+        event       = { class: klass, jid: job_hash["jid"] }
+        event[:bid] = job_hash["bid"] if job_hash["bid"]
+        event
+      end
+    end
+
+    # Let Semantic Logger handle duration logging
+    module Middleware
+      module Server
+        class Logging
+          def call(worker, item, queue)
+            worker.logger.info("Start #perform")
+            worker.logger.measure_info(
+              "Completed #perform",
+              on_exception_level: :error,
+              log_exception:      :full,
+              metric:             "Sidekiq/#{worker.class.name}/perform"
+            ) do
+              yield
+            end
+          end
+        end
+      end
+    end
+  end
+end

lib/rails_semantic_logger/version.rb

@@ -1,3 +1,3 @@
 module RailsSemanticLogger
-  VERSION = "4.14.0".freeze
+  VERSION = "4.15.0".freeze
 end