From b48677dae4283cd1557493225fa52aa80d20767e Mon Sep 17 00:00:00 2001 From: iMacTia Date: Sat, 20 Apr 2019 12:27:04 +0200 Subject: [PATCH 1/8] Adds rubocop and auto-correct whole project. --- .rubocop.yml | 19 ++++++++++ Gemfile | 2 + Rakefile | 8 ++-- bin/console | 1 + bin/test_console | 1 + gemfiles/sidekiq3.gemfile | 2 + gemfiles/sidekiq4.gemfile | 4 +- gemfiles/sidekiq5.gemfile | 4 +- lib/sidekiq/logging/argument_filter.rb | 33 ++++++++++++----- lib/sidekiq/logging/logstash_formatter.rb | 10 ++++- lib/sidekiq/logging/shared.rb | 37 ++++++++++--------- lib/sidekiq/logstash.rb | 4 +- lib/sidekiq/logstash/configuration.rb | 3 ++ lib/sidekiq/logstash/version.rb | 2 + lib/sidekiq/logstash_job_logger.rb | 6 ++- .../middleware/server/logstash_logging.rb | 6 ++- sidekiq-logstash.gemspec | 37 ++++++++++--------- spec/factories/jobs.rb | 10 +++-- .../logging/logstash_formatter_spec.rb | 6 ++- spec/sidekiq/logstash_spec.rb | 2 + spec/spec_helper.rb | 8 ++-- spec/support/factory_girl.rb | 4 +- spec/workers/spec_worker.rb | 2 + 23 files changed, 144 insertions(+), 67 deletions(-) create mode 100644 .rubocop.yml diff --git a/.rubocop.yml b/.rubocop.yml new file mode 100644 index 0000000..00e7b22 --- /dev/null +++ b/.rubocop.yml @@ -0,0 +1,19 @@ +require: + - rubocop-performance + +AllCops: + DisplayCopNames: true + DisplayStyleGuide: true + TargetRubyVersion: 2.3 + +Metrics/BlockLength: + Exclude: + - spec/**/*.rb + +Metrics/LineLength: + Exclude: + - spec/**/*.rb + +Style/Documentation: + Exclude: + - 'spec/**/*' \ No newline at end of file diff --git a/Gemfile b/Gemfile index bae3632..27cf92a 100644 --- a/Gemfile +++ b/Gemfile @@ -1,3 +1,5 @@ +# frozen_string_literal: true + source 'https://rubygems.org' # Specify your gem's dependencies in sidekiq-logstash.gemspec diff --git a/Rakefile b/Rakefile index b7e9ed5..82bb534 100644 --- a/Rakefile +++ b/Rakefile @@ -1,6 +1,8 @@ -require "bundler/gem_tasks" -require "rspec/core/rake_task" +# frozen_string_literal: true + +require 'bundler/gem_tasks' +require 'rspec/core/rake_task' RSpec::Core::RakeTask.new(:spec) -task :default => :spec +task default: :spec diff --git a/bin/console b/bin/console index ae08128..0ebf48f 100755 --- a/bin/console +++ b/bin/console @@ -1,4 +1,5 @@ #!/usr/bin/env ruby +# frozen_string_literal: true require 'bundler/setup' require 'sidekiq/logstash' diff --git a/bin/test_console b/bin/test_console index 5ee3d5a..600f2fc 100755 --- a/bin/test_console +++ b/bin/test_console @@ -1,4 +1,5 @@ #!/usr/bin/env ruby +# frozen_string_literal: true require 'bundler/setup' require 'sidekiq/logstash' diff --git a/gemfiles/sidekiq3.gemfile b/gemfiles/sidekiq3.gemfile index 4a820ff..a2b0cd8 100644 --- a/gemfiles/sidekiq3.gemfile +++ b/gemfiles/sidekiq3.gemfile @@ -1,3 +1,5 @@ +# frozen_string_literal: true + source 'https://rubygems.org' gem 'sidekiq', '~> 3.0' diff --git a/gemfiles/sidekiq4.gemfile b/gemfiles/sidekiq4.gemfile index 250ed78..c5a65ef 100644 --- a/gemfiles/sidekiq4.gemfile +++ b/gemfiles/sidekiq4.gemfile @@ -1,5 +1,7 @@ +# frozen_string_literal: true + source 'https://rubygems.org' gem 'sidekiq', '~> 4.0' -gemspec path: '../' \ No newline at end of file +gemspec path: '../' diff --git a/gemfiles/sidekiq5.gemfile b/gemfiles/sidekiq5.gemfile index 5ccde5e..5d90949 100644 --- a/gemfiles/sidekiq5.gemfile +++ b/gemfiles/sidekiq5.gemfile @@ -1,5 +1,7 @@ +# frozen_string_literal: true + source 'https://rubygems.org' gem 'sidekiq', '~> 5.0' -gemspec path: '../' \ No newline at end of file +gemspec path: '../' diff --git a/lib/sidekiq/logging/argument_filter.rb b/lib/sidekiq/logging/argument_filter.rb index 57e2c13..d1753dc 100644 --- a/lib/sidekiq/logging/argument_filter.rb +++ b/lib/sidekiq/logging/argument_filter.rb @@ -1,10 +1,12 @@ +# frozen_string_literal: true + # This implementation is taken directly from https://github.com/rails/rails/blob/52ce6ece8c8f74064bb64e0a0b1ddd83092718e1/actionpack/lib/action_dispatch/http/parameter_filter.rb # Adding actionpack to the gem dependencies would have been too heavy, so here is just what we need. module Sidekiq module Logging class ArgumentFilter - FILTERED = '[FILTERED]'.freeze + FILTERED = '[FILTERED]' def initialize(filters = []) @filters = filters @@ -22,8 +24,11 @@ def compiled_filter class CompiledFilter # :nodoc: def self.compile(filters) - return lambda { |args| args.dup } if filters.empty? - strings, regexps, blocks = [], [], [] + return ->(args) { args.dup } if filters.empty? + + strings = [] + regexps = [] + blocks = [] filters.each do |item| case item when Proc @@ -34,10 +39,10 @@ def self.compile(filters) strings << Regexp.escape(item.to_s) end end - deep_regexps, regexps = regexps.partition { |r| r.to_s.include?("\\.".freeze) } - deep_strings, strings = strings.partition { |s| s.include?("\\.".freeze) } - regexps << Regexp.new(strings.join('|'.freeze), true) unless strings.empty? - deep_regexps << Regexp.new(deep_strings.join('|'.freeze), true) unless deep_strings.empty? + deep_regexps, regexps = regexps.partition { |r| r.to_s.include?('\\.') } + deep_strings, strings = strings.partition { |s| s.include?('\\.') } + regexps << Regexp.new(strings.join('|'), true) unless strings.empty? + deep_regexps << Regexp.new(deep_strings.join('|'), true) unless deep_strings.empty? new regexps, deep_regexps, blocks end @@ -62,8 +67,16 @@ def call(original_args, parents = []) elsif value.is_a?(Array) value = value.map { |v| v.is_a?(Hash) ? call(v, parents) : v } elsif blocks.any? - key = key.dup rescue key - value = value.dup rescue value + key = begin + key.dup + rescue StandardError + key + end + value = begin + value.dup + rescue StandardError + value + end blocks.each { |b| b.call(key, value) } end parents.pop if deep_regexps @@ -74,4 +87,4 @@ def call(original_args, parents = []) end end end -end \ No newline at end of file +end diff --git a/lib/sidekiq/logging/logstash_formatter.rb b/lib/sidekiq/logging/logstash_formatter.rb index 9bae617..f1fe972 100644 --- a/lib/sidekiq/logging/logstash_formatter.rb +++ b/lib/sidekiq/logging/logstash_formatter.rb @@ -1,9 +1,11 @@ +# frozen_string_literal: true + require 'logstash-event' module Sidekiq module Logging class LogstashFormatter - def call(severity, time, progname, data) + def call(severity, _time, _progname, data) json_data = { severity: severity } if data.is_a? Hash @@ -13,7 +15,11 @@ def call(severity, time, progname, data) end # Merge custom_options to provide customization - custom_options.call(json_data) if custom_options rescue nil + begin + custom_options&.call(json_data) + rescue StandardError + nil + end event = LogStash::Event.new(json_data) "#{event.to_json}\n" diff --git a/lib/sidekiq/logging/shared.rb b/lib/sidekiq/logging/shared.rb index 8bb50c6..f198ce2 100644 --- a/lib/sidekiq/logging/shared.rb +++ b/lib/sidekiq/logging/shared.rb @@ -1,7 +1,9 @@ +# frozen_string_literal: true + module Sidekiq module Logging module Shared - ENCRYPTED = '[ENCRYPTED]'.freeze + ENCRYPTED = '[ENCRYPTED]' def log_job(payload, started_at, exc = nil, start = false) # skip start logs for retrying jobs @@ -12,14 +14,14 @@ def log_job(payload, started_at, exc = nil, start = false) payload = JSON.parse(JSON.unparse(payload)) # Convert timestamps into Time instances - %w( created_at enqueued_at retried_at failed_at completed_at ).each do |key| + %w[created_at enqueued_at retried_at failed_at completed_at].each do |key| payload[key] = parse_time(payload[key]) if payload[key] end message = "#{payload['class']} JID-#{payload['jid']}" # Add process id params - payload['pid'] = ::Process.pid + payload['pid'] = ::Process.pid if start payload['job_status'] = 'started' @@ -28,34 +30,32 @@ def log_job(payload, started_at, exc = nil, start = false) payload['duration'] = elapsed(started_at) if exc - payload['message'] = "#{message}: fail: #{payload['duration']} sec" - payload['job_status'] = 'fail' - payload['error_message'] = exc.message - payload['error'] = exc.class + payload['message'] = "#{message}: fail: #{payload['duration']} sec" + payload['job_status'] = 'fail' + payload['error_message'] = exc.message + payload['error'] = exc.class payload['error_backtrace'] = %('#{exc.backtrace.join("\n")}') else - payload['message'] = "#{message}: done: #{payload['duration']} sec" - payload['job_status'] = 'done' + payload['message'] = "#{message}: done: #{payload['duration']} sec" + payload['job_status'] = 'done' payload['completed_at'] = Time.now.utc end end # Filter sensitive parameters unless filter_args.empty? - args_filter = Sidekiq::Logging::ArgumentFilter.new(filter_args) - payload['args'] = args_filter.filter({ args: payload['args'] })[:args] + args_filter = Sidekiq::Logging::ArgumentFilter.new(filter_args) + payload['args'] = args_filter.filter(args: payload['args'])[:args] end # If encrypt is true, the last arg is encrypted so hide it - if payload['encrypt'] - payload['args'][-1] = ENCRYPTED - end + payload['args'][-1] = ENCRYPTED if payload['encrypt'] # Needs to map all args to strings for ElasticSearch compatibility payload['args'].map!(&:to_s) # Needs to map all unique_args to strings for ElasticSearch compatibility in case sidekiq-unique-jobs is used - payload['unique_args'].map!(&:to_s) if payload['unique_args'] + payload['unique_args']&.map!(&:to_s) if payload['retry'].is_a?(Integer) payload['max_retries'] = payload['retry'] @@ -71,10 +71,11 @@ def elapsed(start) def parse_time(timestamp) return timestamp if timestamp.is_a? Time + timestamp.is_a?(Float) ? - Time.at(timestamp).utc : - Time.parse(timestamp) - rescue + Time.at(timestamp).utc : + Time.parse(timestamp) + rescue StandardError timestamp end diff --git a/lib/sidekiq/logstash.rb b/lib/sidekiq/logstash.rb index fc8715d..6f68bdd 100644 --- a/lib/sidekiq/logstash.rb +++ b/lib/sidekiq/logstash.rb @@ -1,3 +1,5 @@ +# frozen_string_literal: true + require 'sidekiq/logstash/configuration' require 'sidekiq/logstash/version' require 'sidekiq/middleware/server/logstash_logging' @@ -15,7 +17,7 @@ def self.configure yield(configuration) end - def self.setup(opts = {}) + def self.setup(_opts = {}) # Calls Sidekiq.configure_server to inject logics Sidekiq.configure_server do |config| # Remove default Sidekiq error_handler that logs errors diff --git a/lib/sidekiq/logstash/configuration.rb b/lib/sidekiq/logstash/configuration.rb index 7335588..6511463 100644 --- a/lib/sidekiq/logstash/configuration.rb +++ b/lib/sidekiq/logstash/configuration.rb @@ -1,3 +1,5 @@ +# frozen_string_literal: true + module Sidekiq module Logstash class Configuration @@ -11,6 +13,7 @@ def initialize # Added to ensure custom_options is a Proc def custom_options=(proc) raise ArgumentError, 'Argument must be a Proc.' unless proc.is_a?(Proc) + @custom_options = proc end end diff --git a/lib/sidekiq/logstash/version.rb b/lib/sidekiq/logstash/version.rb index 35dda52..677df1a 100644 --- a/lib/sidekiq/logstash/version.rb +++ b/lib/sidekiq/logstash/version.rb @@ -1,3 +1,5 @@ +# frozen_string_literal: true + module Sidekiq module Logstash VERSION = '1.1.0' diff --git a/lib/sidekiq/logstash_job_logger.rb b/lib/sidekiq/logstash_job_logger.rb index f3c9373..e3dba3e 100644 --- a/lib/sidekiq/logstash_job_logger.rb +++ b/lib/sidekiq/logstash_job_logger.rb @@ -1,3 +1,5 @@ +# frozen_string_literal: true + require 'sidekiq/logging/shared' module Sidekiq @@ -12,10 +14,10 @@ def call(job, _queue) end yield Sidekiq.logger.info log_job(job, started_at) - rescue => exc + rescue StandardError => exc begin Sidekiq.logger.warn log_job(job, started_at, exc) - rescue => ex + rescue StandardError => ex Sidekiq.logger.error 'Error logging the job execution!' Sidekiq.logger.error "Job: #{job}" Sidekiq.logger.error "Job Exception: #{exc}" diff --git a/lib/sidekiq/middleware/server/logstash_logging.rb b/lib/sidekiq/middleware/server/logstash_logging.rb index f3867f3..cc6a750 100644 --- a/lib/sidekiq/middleware/server/logstash_logging.rb +++ b/lib/sidekiq/middleware/server/logstash_logging.rb @@ -1,3 +1,5 @@ +# frozen_string_literal: true + require 'sidekiq/logging/shared' module Sidekiq @@ -10,10 +12,10 @@ def call(_, job, _) started_at = Time.now.utc yield Sidekiq.logger.info log_job(job, started_at) - rescue => exc + rescue StandardError => exc begin Sidekiq.logger.warn log_job(job, started_at, exc) - rescue => ex + rescue StandardError => ex Sidekiq.logger.error 'Error logging the job execution!' Sidekiq.logger.error "Job: #{job}" Sidekiq.logger.error "Job Exception: #{exc}" diff --git a/sidekiq-logstash.gemspec b/sidekiq-logstash.gemspec index faaee4f..8989ac8 100644 --- a/sidekiq-logstash.gemspec +++ b/sidekiq-logstash.gemspec @@ -1,32 +1,35 @@ -# coding: utf-8 -lib = File.expand_path('../lib', __FILE__) +# frozen_string_literal: true + +lib = File.expand_path('lib', __dir__) $LOAD_PATH.unshift(lib) unless $LOAD_PATH.include?(lib) require 'sidekiq/logstash/version' Gem::Specification.new do |spec| - spec.name = 'sidekiq-logstash' - spec.version = Sidekiq::Logstash::VERSION - spec.authors = ['Mattia Giuffrida'] - spec.email = ['giuffrida.mattia@gmail.com'] + spec.name = 'sidekiq-logstash' + spec.version = Sidekiq::Logstash::VERSION + spec.authors = ['Mattia Giuffrida'] + spec.email = ['giuffrida.mattia@gmail.com'] - spec.summary = %q{Logstash plugin for Sidekiq} - spec.description = <<-DESC -Sidekiq::Logstash turns your Sidekiq log into an organised, aggregated, JSON-syntax log ready to be sent to a logstash server. -DESC - spec.homepage = 'https://github.com/iMacTia/sidekiq-logstash' - spec.license = 'MIT' + spec.summary = 'Logstash plugin for Sidekiq' + spec.description = <<~DESC + Sidekiq::Logstash turns your Sidekiq log into an organised, aggregated, JSON-syntax log ready to be sent to a logstash server. + DESC + spec.homepage = 'https://github.com/iMacTia/sidekiq-logstash' + spec.license = 'MIT' - spec.files = `git ls-files -z`.split("\x0").reject { |f| f.match(%r{^(test|spec|features)/}) } - spec.bindir = 'exe' - spec.executables = spec.files.grep(%r{^exe/}) { |f| File.basename(f) } + spec.files = `git ls-files -z`.split("\x0").reject { |f| f.match(%r{^(test|spec|features)/}) } + spec.bindir = 'exe' + spec.executables = spec.files.grep(%r{^exe/}) { |f| File.basename(f) } spec.require_paths = ['lib'] spec.add_dependency 'logstash-event', '~> 1.2' - spec.add_runtime_dependency 'sidekiq', '>= 3.0' , '<6' + spec.add_runtime_dependency 'sidekiq', '>= 3.0', '<6' spec.add_development_dependency 'bundler', '~> 1.11' + spec.add_development_dependency 'factory_girl', '~> 4.0' spec.add_development_dependency 'rake', '~> 10.0' spec.add_development_dependency 'rspec', '~> 3.0' spec.add_development_dependency 'rspec-json_expectations', '~> 2.1.0' - spec.add_development_dependency 'factory_girl', '~> 4.0' + spec.add_development_dependency 'rubocop', '~> 0.67.2' + spec.add_development_dependency 'rubocop-performance' end diff --git a/spec/factories/jobs.rb b/spec/factories/jobs.rb index e15232a..03a375c 100644 --- a/spec/factories/jobs.rb +++ b/spec/factories/jobs.rb @@ -1,13 +1,15 @@ +# frozen_string_literal: true + FactoryGirl.define do factory :job, class: Hash do args [ 'just a simple string', { object_name: 'stars', - object_id: Kernel.rand(10000), + object_id: Kernel.rand(10_000), data: { - id: Kernel.rand(10000), - num_units: Kernel.rand(10000) * Kernel.rand + id: Kernel.rand(10_000), + num_units: Kernel.rand(10_000) * Kernel.rand }.stringify_keys }.stringify_keys, { @@ -20,7 +22,7 @@ enqueued_at '2016-07-06T18:18:25.499Z' encrypt false - initialize_with {attributes.stringify_keys} + initialize_with { attributes.stringify_keys } after(:build) do |job| if job['encrypt'] job['args'][-1] = 'BAhTOhFTaWRla2lxOjpFbmMIOgdpdiIVo1mbHmnVxiOIT' diff --git a/spec/sidekiq/logging/logstash_formatter_spec.rb b/spec/sidekiq/logging/logstash_formatter_spec.rb index 25fab72..cad561e 100644 --- a/spec/sidekiq/logging/logstash_formatter_spec.rb +++ b/spec/sidekiq/logging/logstash_formatter_spec.rb @@ -1,3 +1,5 @@ +# frozen_string_literal: true + require 'spec_helper' require 'sidekiq/logging/logstash_formatter' @@ -14,8 +16,8 @@ it 'preserves severity of given hash' do data = { - severity: 'WARN', - message: 'the message', + severity: 'WARN', + message: 'the message' } json = logstash_formatter.call('INFO', Time.now, 'progname', data) diff --git a/spec/sidekiq/logstash_spec.rb b/spec/sidekiq/logstash_spec.rb index d139e9f..1a0ff73 100644 --- a/spec/sidekiq/logstash_spec.rb +++ b/spec/sidekiq/logstash_spec.rb @@ -1,3 +1,5 @@ +# frozen_string_literal: true + require 'spec_helper' require 'workers/spec_worker' diff --git a/spec/spec_helper.rb b/spec/spec_helper.rb index d254cb8..39b6590 100644 --- a/spec/spec_helper.rb +++ b/spec/spec_helper.rb @@ -1,5 +1,7 @@ -$LOAD_PATH.unshift File.expand_path('../../lib', __FILE__) -$LOAD_PATH.unshift File.expand_path('..', __FILE__) +# frozen_string_literal: true + +$LOAD_PATH.unshift File.expand_path('../lib', __dir__) +$LOAD_PATH.unshift File.expand_path(__dir__) require 'sidekiq/logstash' require 'logstash-event' @@ -10,4 +12,4 @@ require 'forwardable' # needed by rspec-json_expectations require 'rspec/json_expectations' require 'factory_girl' -require 'support/factory_girl' \ No newline at end of file +require 'support/factory_girl' diff --git a/spec/support/factory_girl.rb b/spec/support/factory_girl.rb index 4ece383..d4f1532 100644 --- a/spec/support/factory_girl.rb +++ b/spec/support/factory_girl.rb @@ -1,7 +1,9 @@ +# frozen_string_literal: true + RSpec.configure do |config| config.include FactoryGirl::Syntax::Methods config.before(:suite) do FactoryGirl.find_definitions end -end \ No newline at end of file +end diff --git a/spec/workers/spec_worker.rb b/spec/workers/spec_worker.rb index 78efc50..a7ed45a 100644 --- a/spec/workers/spec_worker.rb +++ b/spec/workers/spec_worker.rb @@ -1,3 +1,5 @@ +# frozen_string_literal: true + class SpecWorker include Sidekiq::Worker From eabe436f365c04373da11dee14a909524a319d7d Mon Sep 17 00:00:00 2001 From: iMacTia Date: Sat, 20 Apr 2019 13:21:13 +0200 Subject: [PATCH 2/8] Refactors shared, logstash_logging and logstash_log_jobber to remove duplication. --- .rubocop.yml | 1 + lib/sidekiq/logging/shared.rb | 95 +++++++++++++------ lib/sidekiq/logstash_job_logger.rb | 20 +--- .../middleware/server/logstash_logging.rb | 16 +--- spec/sidekiq/logstash_spec.rb | 41 ++++---- 5 files changed, 93 insertions(+), 80 deletions(-) diff --git a/.rubocop.yml b/.rubocop.yml index 00e7b22..e343b44 100644 --- a/.rubocop.yml +++ b/.rubocop.yml @@ -11,6 +11,7 @@ Metrics/BlockLength: - spec/**/*.rb Metrics/LineLength: + Max: 120 Exclude: - spec/**/*.rb diff --git a/lib/sidekiq/logging/shared.rb b/lib/sidekiq/logging/shared.rb index f198ce2..be46509 100644 --- a/lib/sidekiq/logging/shared.rb +++ b/lib/sidekiq/logging/shared.rb @@ -5,43 +5,78 @@ module Logging module Shared ENCRYPTED = '[ENCRYPTED]' - def log_job(payload, started_at, exc = nil, start = false) - # skip start logs for retrying jobs - return if start && payload['failed_at'] + def log_job(job) + started_at = Time.now.utc + log_start = log_job_start(job) + Sidekiq.logger.info log_start if log_start + yield if block_given? + Sidekiq.logger.info log_job_exec(job, started_at) + rescue StandardError => e + begin + Sidekiq.logger.warn log_job_exception(job, started_at, e) + rescue StandardError => ex + log_standard_error(job, e, ex) + end + raise + end + + def log_job_start(job) + return unless Sidekiq::Logstash.configuration.job_start_log + # Skips start logs for retrying jobs + return if job['failed_at'] + + payload = setup_payload(job) + payload['job_status'] = 'started' + payload['message'] += ': started' + process_payload(payload) + end + + def log_job_exec(job, started_at) + payload = setup_payload(job) + payload['duration'] = elapsed(started_at) + + payload['message'] += ": done: #{payload['duration']} sec" + payload['job_status'] = 'done' + payload['completed_at'] = Time.now.utc + + process_payload(payload) + end + + def log_job_exception(job, started_at, exc) + payload = setup_payload(job) + payload['duration'] = elapsed(started_at) + payload['message'] += ": fail: #{payload['duration']} sec" + payload['job_status'] = 'fail' + payload['error_message'] = exc.message + payload['error'] = exc.class + payload['error_backtrace'] = %('#{exc.backtrace.join("\n")}') + + process_payload(payload) + end + + private + + def setup_payload(job) # Create a copy of the payload using JSON # This should always be possible since Sidekiq store it in Redis - payload = JSON.parse(JSON.unparse(payload)) + payload = JSON.parse(JSON.unparse(job)) # Convert timestamps into Time instances %w[created_at enqueued_at retried_at failed_at completed_at].each do |key| payload[key] = parse_time(payload[key]) if payload[key] end - message = "#{payload['class']} JID-#{payload['jid']}" + # Sets the initial message + payload['message'] = "#{payload['class']} JID-#{payload['jid']}" # Add process id params payload['pid'] = ::Process.pid - if start - payload['job_status'] = 'started' - payload['message'] = "#{message}: started" - else - payload['duration'] = elapsed(started_at) - - if exc - payload['message'] = "#{message}: fail: #{payload['duration']} sec" - payload['job_status'] = 'fail' - payload['error_message'] = exc.message - payload['error'] = exc.class - payload['error_backtrace'] = %('#{exc.backtrace.join("\n")}') - else - payload['message'] = "#{message}: done: #{payload['duration']} sec" - payload['job_status'] = 'done' - payload['completed_at'] = Time.now.utc - end - end + payload + end + def process_payload(payload) # Filter sensitive parameters unless filter_args.empty? args_filter = Sidekiq::Logging::ArgumentFilter.new(filter_args) @@ -54,7 +89,8 @@ def log_job(payload, started_at, exc = nil, start = false) # Needs to map all args to strings for ElasticSearch compatibility payload['args'].map!(&:to_s) - # Needs to map all unique_args to strings for ElasticSearch compatibility in case sidekiq-unique-jobs is used + # Needs to map all unique_args to strings for ElasticSearch + # compatibility in case sidekiq-unique-jobs is used payload['unique_args']&.map!(&:to_s) if payload['retry'].is_a?(Integer) @@ -65,6 +101,13 @@ def log_job(payload, started_at, exc = nil, start = false) payload end + def log_standard_error(job, job_exc, log_exc) + Sidekiq.logger.error 'Error logging the job execution!' + Sidekiq.logger.error "Job: #{job}" + Sidekiq.logger.error "Job Exception: #{job_exc}" + Sidekiq.logger.error "Log Exception: #{log_exc}" + end + def elapsed(start) (Time.now.utc - start).round(3) end @@ -72,9 +115,7 @@ def elapsed(start) def parse_time(timestamp) return timestamp if timestamp.is_a? Time - timestamp.is_a?(Float) ? - Time.at(timestamp).utc : - Time.parse(timestamp) + timestamp.is_a?(Float) ? Time.at(timestamp).utc : Time.parse(timestamp) rescue StandardError timestamp end diff --git a/lib/sidekiq/logstash_job_logger.rb b/lib/sidekiq/logstash_job_logger.rb index e3dba3e..f9c9c97 100644 --- a/lib/sidekiq/logstash_job_logger.rb +++ b/lib/sidekiq/logstash_job_logger.rb @@ -6,24 +6,8 @@ module Sidekiq class LogstashJobLogger include Sidekiq::Logging::Shared - def call(job, _queue) - started_at = Time.now.utc - if Sidekiq::Logstash.configuration.job_start_log - payload = log_job(job, started_at, nil, true) - Sidekiq.logger.info payload if payload - end - yield - Sidekiq.logger.info log_job(job, started_at) - rescue StandardError => exc - begin - Sidekiq.logger.warn log_job(job, started_at, exc) - rescue StandardError => ex - Sidekiq.logger.error 'Error logging the job execution!' - Sidekiq.logger.error "Job: #{job}" - Sidekiq.logger.error "Job Exception: #{exc}" - Sidekiq.logger.error "Log Exception: #{ex}" - end - raise + def call(job, _queue, &block) + log_job(job, &block) end end end diff --git a/lib/sidekiq/middleware/server/logstash_logging.rb b/lib/sidekiq/middleware/server/logstash_logging.rb index cc6a750..90327f0 100644 --- a/lib/sidekiq/middleware/server/logstash_logging.rb +++ b/lib/sidekiq/middleware/server/logstash_logging.rb @@ -8,20 +8,8 @@ module Server class LogstashLogging include Sidekiq::Logging::Shared - def call(_, job, _) - started_at = Time.now.utc - yield - Sidekiq.logger.info log_job(job, started_at) - rescue StandardError => exc - begin - Sidekiq.logger.warn log_job(job, started_at, exc) - rescue StandardError => ex - Sidekiq.logger.error 'Error logging the job execution!' - Sidekiq.logger.error "Job: #{job}" - Sidekiq.logger.error "Job Exception: #{exc}" - Sidekiq.logger.error "Log Exception: #{ex}" - end - raise + def call(_, job, _, &block) + log_job(job, &block) end end end diff --git a/spec/sidekiq/logstash_spec.rb b/spec/sidekiq/logstash_spec.rb index 1a0ff73..a6172ea 100644 --- a/spec/sidekiq/logstash_spec.rb +++ b/spec/sidekiq/logstash_spec.rb @@ -4,11 +4,10 @@ require 'workers/spec_worker' describe Sidekiq::Logstash do - before(:each) do - Sidekiq.logger = double(Logger.new(STDOUT)) - end + let(:buffer) { StringIO.new } + let(:job) { FactoryGirl.build(:job) } - let (:job) { FactoryGirl.build(:job) } + before { Sidekiq.logger = Logger.new(buffer) } it 'has a version number' do expect(Sidekiq::Logstash::VERSION).not_to be nil @@ -30,7 +29,7 @@ buffer = StringIO.new Sidekiq.logger = Logger.new(buffer) - log_job = Sidekiq::LogstashJobLogger.new.call(job, :default) {} + Sidekiq::LogstashJobLogger.new.call(job, :default) {} expect(buffer.string.split("\n").length).to eq(1) expect(buffer.string).not_to include('"job_status"=>"started"') @@ -40,8 +39,8 @@ Sidekiq::Logstash.configure do |config| config.filter_args << 'a_secret_param' end - log_job = Sidekiq::Middleware::Server::LogstashLogging.new.log_job(job, Time.now.utc) - expect(log_job['args'][2]).to include('[FILTERED]') + Sidekiq::LogstashJobLogger.new.log_job(job) + expect(buffer.string).to include('[FILTERED]') end it 'add custom options' do @@ -56,37 +55,37 @@ end context 'when a job has encrypted arguments' do - let (:job) { FactoryGirl.build(:job, encrypt: true) } + let(:job) { FactoryGirl.build(:job, encrypt: true) } it 'hides encrypted args' do - log_job = Sidekiq::Middleware::Server::LogstashLogging.new.log_job(job, Time.now.utc) - expect(log_job['args'][2]).to include('[ENCRYPTED]') + Sidekiq::LogstashJobLogger.new.log_job(job) + expect(buffer.string).to include('[ENCRYPTED]') end end context 'enable job_start_log' do - it 'generates log with job_status=started' do - buffer = StringIO.new + before do Sidekiq.logger = Logger.new(buffer) Sidekiq::Logstash.configure do |config| config.job_start_log = true end + end + + after do + Sidekiq::Logstash.configure do |config| + config.job_start_log = false + end + end - log_job = Sidekiq::Middleware::Server::LogstashLogging.new.log_job(job, Time.now.utc, exc = nil, start = true) + it 'generates log with job_status=started' do + log_job = Sidekiq::LogstashJobLogger.new.log_job_start(job) expect(log_job['job_status']).to eq('started') end it 'logs both the starting and finished logs' do - buffer = StringIO.new - Sidekiq.logger = Logger.new(buffer) - - Sidekiq::Logstash.configure do |config| - config.job_start_log = true - end - - log_job = Sidekiq::LogstashJobLogger.new.call(job, :default) {} + Sidekiq::LogstashJobLogger.new.call(job, :default) {} expect(buffer.string.split("\n").length).to eq(2) expect(buffer.string).to include('"job_status"=>"started"') From 0015de2bfe9ac237587a4adb09365a136b4224e6 Mon Sep 17 00:00:00 2001 From: iMacTia Date: Sat, 20 Apr 2019 13:25:03 +0200 Subject: [PATCH 3/8] Adds remaining Rubocop offenses to .rubocop_todo.yml --- .rubocop.yml | 2 ++ .rubocop_todo.yml | 41 ++++++++++++++++++++++++++ lib/sidekiq/logging/argument_filter.rb | 1 - spec/factories/jobs.rb | 4 +-- 4 files changed, 44 insertions(+), 4 deletions(-) create mode 100644 .rubocop_todo.yml diff --git a/.rubocop.yml b/.rubocop.yml index e343b44..cb1b202 100644 --- a/.rubocop.yml +++ b/.rubocop.yml @@ -1,3 +1,5 @@ +inherit_from: .rubocop_todo.yml + require: - rubocop-performance diff --git a/.rubocop_todo.yml b/.rubocop_todo.yml new file mode 100644 index 0000000..258fd43 --- /dev/null +++ b/.rubocop_todo.yml @@ -0,0 +1,41 @@ +# This configuration was generated by +# `rubocop --auto-gen-config` +# on 2019-04-20 13:23:53 +0200 using RuboCop version 0.67.2. +# The point is for the user to remove these configuration records +# one by one as the offenses are removed from the code base. +# Note that changes in the inspected code, or installation of new +# versions of RuboCop, may require this file to be generated again. + +# Offense count: 1 +Lint/DuplicateMethods: + Exclude: + - 'lib/sidekiq/logstash/configuration.rb' + +# Offense count: 4 +Metrics/AbcSize: + Max: 31 + +# Offense count: 1 +Metrics/CyclomaticComplexity: + Max: 13 + +# Offense count: 6 +# Configuration parameters: CountComments, ExcludedMethods. +Metrics/MethodLength: + Max: 28 + +# Offense count: 1 +Metrics/PerceivedComplexity: + Max: 14 + +# Offense count: 7 +Style/Documentation: + Exclude: + - 'spec/**/*' + - 'lib/sidekiq/logging/argument_filter.rb' + - 'lib/sidekiq/logging/logstash_formatter.rb' + - 'lib/sidekiq/logging/shared.rb' + - 'lib/sidekiq/logstash.rb' + - 'lib/sidekiq/logstash/configuration.rb' + - 'lib/sidekiq/logstash_job_logger.rb' + - 'lib/sidekiq/middleware/server/logstash_logging.rb' diff --git a/lib/sidekiq/logging/argument_filter.rb b/lib/sidekiq/logging/argument_filter.rb index d1753dc..4fb0370 100644 --- a/lib/sidekiq/logging/argument_filter.rb +++ b/lib/sidekiq/logging/argument_filter.rb @@ -2,7 +2,6 @@ # This implementation is taken directly from https://github.com/rails/rails/blob/52ce6ece8c8f74064bb64e0a0b1ddd83092718e1/actionpack/lib/action_dispatch/http/parameter_filter.rb # Adding actionpack to the gem dependencies would have been too heavy, so here is just what we need. - module Sidekiq module Logging class ArgumentFilter diff --git a/spec/factories/jobs.rb b/spec/factories/jobs.rb index 03a375c..00fbec7 100644 --- a/spec/factories/jobs.rb +++ b/spec/factories/jobs.rb @@ -24,9 +24,7 @@ initialize_with { attributes.stringify_keys } after(:build) do |job| - if job['encrypt'] - job['args'][-1] = 'BAhTOhFTaWRla2lxOjpFbmMIOgdpdiIVo1mbHmnVxiOIT' - end + job['args'][-1] = 'BAhTOhFTaWRla2lxOjpFbmMIOgdpdiIVo1mbHmnVxiOIT' if job['encrypt'] end end end From 92544b927e04f4d185181ce16fff43b9aa2bb223 Mon Sep 17 00:00:00 2001 From: iMacTia Date: Sat, 20 Apr 2019 13:33:14 +0200 Subject: [PATCH 4/8] Documents Modules and Classes as expected by Rubocop. --- lib/sidekiq/logging/argument_filter.rb | 4 ++++ lib/sidekiq/logging/logstash_formatter.rb | 3 +++ lib/sidekiq/logging/shared.rb | 1 + lib/sidekiq/logstash.rb | 3 +++ lib/sidekiq/logstash/configuration.rb | 1 + lib/sidekiq/logstash_job_logger.rb | 1 + lib/sidekiq/middleware/server/logstash_logging.rb | 1 + 7 files changed, 14 insertions(+) diff --git a/lib/sidekiq/logging/argument_filter.rb b/lib/sidekiq/logging/argument_filter.rb index 4fb0370..0c3f3d2 100644 --- a/lib/sidekiq/logging/argument_filter.rb +++ b/lib/sidekiq/logging/argument_filter.rb @@ -4,13 +4,17 @@ # Adding actionpack to the gem dependencies would have been too heavy, so here is just what we need. module Sidekiq module Logging + # Class that allows to filter-out sensible arguments. class ArgumentFilter + # String used to replace sensible arguments. FILTERED = '[FILTERED]' def initialize(filters = []) @filters = filters end + # Filters argument by using the filters provided upon initialization. + # @param args [Array] the list of arguments. def filter(args) compiled_filter.call(args) end diff --git a/lib/sidekiq/logging/logstash_formatter.rb b/lib/sidekiq/logging/logstash_formatter.rb index f1fe972..67c15cd 100644 --- a/lib/sidekiq/logging/logstash_formatter.rb +++ b/lib/sidekiq/logging/logstash_formatter.rb @@ -4,6 +4,7 @@ module Sidekiq module Logging + # Class that takes a log payload and format it to be Logstash-compatible. class LogstashFormatter def call(severity, _time, _progname, data) json_data = { severity: severity } @@ -25,6 +26,8 @@ def call(severity, _time, _progname, data) "#{event.to_json}\n" end + private + def custom_options Sidekiq::Logstash.configuration.custom_options end diff --git a/lib/sidekiq/logging/shared.rb b/lib/sidekiq/logging/shared.rb index be46509..c22f714 100644 --- a/lib/sidekiq/logging/shared.rb +++ b/lib/sidekiq/logging/shared.rb @@ -2,6 +2,7 @@ module Sidekiq module Logging + # Shared module with all the logics used by job loggers. module Shared ENCRYPTED = '[ENCRYPTED]' diff --git a/lib/sidekiq/logstash.rb b/lib/sidekiq/logstash.rb index 6f68bdd..6b2fa07 100644 --- a/lib/sidekiq/logstash.rb +++ b/lib/sidekiq/logstash.rb @@ -8,6 +8,9 @@ require 'sidekiq/logstash_job_logger' module Sidekiq + # Main level module for Sidekiq::Logstash. + # Provides integration between Sidekiq and Logstash by changing the way + # Sidekiq jobs are logged. module Logstash def self.configuration @configuration ||= Configuration.new diff --git a/lib/sidekiq/logstash/configuration.rb b/lib/sidekiq/logstash/configuration.rb index 6511463..b539648 100644 --- a/lib/sidekiq/logstash/configuration.rb +++ b/lib/sidekiq/logstash/configuration.rb @@ -2,6 +2,7 @@ module Sidekiq module Logstash + # Class that allows to configure the gem behaviour. class Configuration attr_accessor :custom_options, :filter_args, :job_start_log diff --git a/lib/sidekiq/logstash_job_logger.rb b/lib/sidekiq/logstash_job_logger.rb index f9c9c97..278314e 100644 --- a/lib/sidekiq/logstash_job_logger.rb +++ b/lib/sidekiq/logstash_job_logger.rb @@ -3,6 +3,7 @@ require 'sidekiq/logging/shared' module Sidekiq + # Class used to replace Sidekiq 5 job logger. class LogstashJobLogger include Sidekiq::Logging::Shared diff --git a/lib/sidekiq/middleware/server/logstash_logging.rb b/lib/sidekiq/middleware/server/logstash_logging.rb index 90327f0..aeaa08a 100644 --- a/lib/sidekiq/middleware/server/logstash_logging.rb +++ b/lib/sidekiq/middleware/server/logstash_logging.rb @@ -5,6 +5,7 @@ module Sidekiq module Middleware module Server + # Class used to replace Sidekiq 4 job logger. class LogstashLogging include Sidekiq::Logging::Shared From 9b6f8639528507b204bd71739bd34e8e30cdafd4 Mon Sep 17 00:00:00 2001 From: iMacTia Date: Sat, 20 Apr 2019 13:41:28 +0200 Subject: [PATCH 5/8] Updates Travis matrix dropping Ruby 2.2 and adding 2.5 and 2.6. --- .travis.yml | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/.travis.yml b/.travis.yml index c755151..cf6b1a5 100644 --- a/.travis.yml +++ b/.travis.yml @@ -1,8 +1,9 @@ language: ruby rvm: -- 2.2.2 -- 2.3.0 -- 2.4.0 +- 2.3 +- 2.4 +- 2.5 +- 2.6 before_install: gem install bundler -v 1.11.2 gemfile: - gemfiles/sidekiq3.gemfile @@ -16,5 +17,5 @@ deploy: on: tags: true repo: iMacTia/sidekiq-logstash - rvm: 2.4.0 + rvm: 2.6 From ad421565ad2b27332b166e6d39c8e87399743003 Mon Sep 17 00:00:00 2001 From: iMacTia Date: Sat, 20 Apr 2019 13:48:19 +0200 Subject: [PATCH 6/8] Use more recent bundler version. --- .travis.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.travis.yml b/.travis.yml index cf6b1a5..0c4e2b9 100644 --- a/.travis.yml +++ b/.travis.yml @@ -4,7 +4,7 @@ rvm: - 2.4 - 2.5 - 2.6 -before_install: gem install bundler -v 1.11.2 +before_install: gem install bundler -v '~> 1.17' gemfile: - gemfiles/sidekiq3.gemfile - gemfiles/sidekiq4.gemfile From d9ca701e1da641ad0958a6e1553e50d22b974ab0 Mon Sep 17 00:00:00 2001 From: iMacTia Date: Sun, 21 Apr 2019 10:04:41 +0200 Subject: [PATCH 7/8] Relaxes Bundler version in Gemspec --- sidekiq-logstash.gemspec | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sidekiq-logstash.gemspec b/sidekiq-logstash.gemspec index 8989ac8..86bb79d 100644 --- a/sidekiq-logstash.gemspec +++ b/sidekiq-logstash.gemspec @@ -25,7 +25,7 @@ Gem::Specification.new do |spec| spec.add_dependency 'logstash-event', '~> 1.2' spec.add_runtime_dependency 'sidekiq', '>= 3.0', '<6' - spec.add_development_dependency 'bundler', '~> 1.11' + spec.add_development_dependency 'bundler', '< 2' spec.add_development_dependency 'factory_girl', '~> 4.0' spec.add_development_dependency 'rake', '~> 10.0' spec.add_development_dependency 'rspec', '~> 3.0' From 4a1e01a6ad56a827c7b22467b57c53978a078093 Mon Sep 17 00:00:00 2001 From: iMacTia Date: Sun, 21 Apr 2019 10:31:45 +0200 Subject: [PATCH 8/8] Tries to fix bundler issue as explained here: https://docs.travis-ci.com/user/languages/ruby/#bundler-20 --- .travis.yml | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/.travis.yml b/.travis.yml index 0c4e2b9..8a33869 100644 --- a/.travis.yml +++ b/.travis.yml @@ -1,10 +1,13 @@ language: ruby +cache: bundler rvm: - 2.3 - 2.4 - 2.5 - 2.6 -before_install: gem install bundler -v '~> 1.17' +before_install: + - gem uninstall -v '>= 2' -i $(rvm gemdir)@global -ax bundler || true + - gem install bundler -v '~> 1.17' gemfile: - gemfiles/sidekiq3.gemfile - gemfiles/sidekiq4.gemfile