From c9e26197b0abbe50b029c368017243314d572884 Mon Sep 17 00:00:00 2001 From: Alberto Vena Date: Mon, 12 Jul 2021 15:29:53 +0200 Subject: Logs an error in the Rails logs when installment processing fails At the moment, by default, all installment prceissing errors are swallowed and there's no way for a developer to understand what's happening. Of course they can create a custom handler with the processing_error_handler configuration provided but usually, when the first errors happen, it's too late and those errors are lost. We are not raising errors of this job because if there's a retry mechanism in place for Active Job, the installment will be reprocessed twice. Once by Active Job and once by the installment retry mechanism already provided by the extension. Logging to Rails.error is a middle-ground that allows to intercept the message of the exception. Still, creating a custom handler based on the bug tracker/exception handler used is the suggested option here. --- .../install/templates/initializer.rb | 4 +++- lib/solidus_subscriptions/configuration.rb | 9 +++++++-- lib/solidus_subscriptions/engine.rb | 1 + .../processing_error_handlers/rails_logger.rb | 23 ++++++++++++++++++++++ .../process_installment_job_spec.rb | 15 ++++++++++++++ 5 files changed, 49 insertions(+), 3 deletions(-) create mode 100644 lib/solidus_subscriptions/processing_error_handlers/rails_logger.rb diff --git a/lib/generators/solidus_subscriptions/install/templates/initializer.rb b/lib/generators/solidus_subscriptions/install/templates/initializer.rb index de1d081..7ca79c5 100644 --- a/lib/generators/solidus_subscriptions/install/templates/initializer.rb +++ b/lib/generators/solidus_subscriptions/install/templates/initializer.rb @@ -31,7 +31,9 @@ SolidusSubscriptions.configure do |config| # on an error tracking system. # Though not recommended due to the retry mechanisms built into this gem, the error can be # re-raised if the default retry behaviour is required in ActiveJob. - # config.processing_error_handler = nil + # + # By default, it only logs the error message using Rails.logger.error. + # config.processing_error_handler = SolidusSubscriptions::ProcessingErrorHandlers::RailsLogger # ========================================= Dispatchers ========================================== # diff --git a/lib/solidus_subscriptions/configuration.rb b/lib/solidus_subscriptions/configuration.rb index 9d6c3d2..350fabc 100644 --- a/lib/solidus_subscriptions/configuration.rb +++ b/lib/solidus_subscriptions/configuration.rb @@ -4,14 +4,14 @@ module SolidusSubscriptions class Configuration attr_accessor( :maximum_total_skips, :maximum_reprocessing_time, :churn_buster_account_id, - :churn_buster_api_key, :clear_past_installments, :processing_error_handler + :churn_buster_api_key, :clear_past_installments ) attr_writer( :success_dispatcher_class, :failure_dispatcher_class, :payment_failed_dispatcher_class, :out_of_stock_dispatcher, :maximum_successive_skips, :reprocessing_interval, :minimum_cancellation_notice, :processing_queue, :subscription_line_item_attributes, - :subscription_attributes, :subscribable_class, :order_creator_class + :subscription_attributes, :subscribable_class, :order_creator_class, :processing_error_handler ) def success_dispatcher_class @@ -34,6 +34,11 @@ module SolidusSubscriptions @out_of_stock_dispatcher_class.constantize end + def processing_error_handler + @processing_error_handler ||= 'SolidusSubscriptions::ProcessingErrorHandlers::RailsLogger' + @processing_error_handler.constantize + end + def maximum_successive_skips @maximum_successive_skips ||= 1 end diff --git a/lib/solidus_subscriptions/engine.rb b/lib/solidus_subscriptions/engine.rb index 0f274d8..2d361cf 100644 --- a/lib/solidus_subscriptions/engine.rb +++ b/lib/solidus_subscriptions/engine.rb @@ -6,6 +6,7 @@ require 'solidus_subscriptions' require 'solidus_subscriptions/permitted_attributes' require 'solidus_subscriptions/configuration' require 'solidus_subscriptions/processor' +require 'solidus_subscriptions/processing_error_handlers/rails_logger' module SolidusSubscriptions class Engine < Rails::Engine diff --git a/lib/solidus_subscriptions/processing_error_handlers/rails_logger.rb b/lib/solidus_subscriptions/processing_error_handlers/rails_logger.rb new file mode 100644 index 0000000..d209123 --- /dev/null +++ b/lib/solidus_subscriptions/processing_error_handlers/rails_logger.rb @@ -0,0 +1,23 @@ +# frozen_string_literal: true + +module SolidusSubscriptions + module ProcessingErrorHandlers + class RailsLogger + def self.call(exception) + new(exception).call + end + + def initialize(exception) + @exception = exception + end + + def call + Rails.logger.error exception.message + end + + private + + attr_reader :exception + end + end +end diff --git a/spec/jobs/solidus_subscriptions/process_installment_job_spec.rb b/spec/jobs/solidus_subscriptions/process_installment_job_spec.rb index bc33d0e..7211cfe 100644 --- a/spec/jobs/solidus_subscriptions/process_installment_job_spec.rb +++ b/spec/jobs/solidus_subscriptions/process_installment_job_spec.rb @@ -12,7 +12,22 @@ RSpec.describe SolidusSubscriptions::ProcessInstallmentJob do end context 'when handling #perform errors' do + it 'by default logs exception data without raising exceptions' do + checkout = instance_double(SolidusSubscriptions::Checkout).tap do |c| + allow(c).to receive(:process).and_raise('test error') + end + allow(SolidusSubscriptions::Checkout).to receive(:new).and_return(checkout) + allow(Rails.logger).to receive(:error) + + expect { + described_class.perform_now(build_stubbed(:installment)) + }.not_to raise_error + + expect(Rails.logger).to have_received(:error).with("test error").ordered + end + it 'swallows error when a proc is not configured' do + stub_config(processing_error_handler: nil ) checkout = instance_double(SolidusSubscriptions::Checkout).tap do |c| allow(c).to receive(:process).and_raise('test error') end -- cgit v1.2.3 From 0317e228bc79c13667940203add35fa13fac21f1 Mon Sep 17 00:00:00 2001 From: Alberto Vena Date: Mon, 12 Jul 2021 17:04:48 +0200 Subject: Pass installment to the processing error handler This way we can provide more flexibility on things that can be done when an error occurs. In the provided RailsLogger handler, we'll also print the ID of the installment. --- app/jobs/solidus_subscriptions/process_installment_job.rb | 2 +- .../processing_error_handlers/rails_logger.rb | 12 +++++++----- .../solidus_subscriptions/process_installment_job_spec.rb | 6 ++++-- 3 files changed, 12 insertions(+), 8 deletions(-) diff --git a/app/jobs/solidus_subscriptions/process_installment_job.rb b/app/jobs/solidus_subscriptions/process_installment_job.rb index 53270e5..84d077a 100644 --- a/app/jobs/solidus_subscriptions/process_installment_job.rb +++ b/app/jobs/solidus_subscriptions/process_installment_job.rb @@ -7,7 +7,7 @@ module SolidusSubscriptions def perform(installment) Checkout.new(installment).process rescue StandardError => e - SolidusSubscriptions.configuration.processing_error_handler&.call(e) + SolidusSubscriptions.configuration.processing_error_handler&.call(e, installment) end end end diff --git a/lib/solidus_subscriptions/processing_error_handlers/rails_logger.rb b/lib/solidus_subscriptions/processing_error_handlers/rails_logger.rb index d209123..d6fcf7e 100644 --- a/lib/solidus_subscriptions/processing_error_handlers/rails_logger.rb +++ b/lib/solidus_subscriptions/processing_error_handlers/rails_logger.rb @@ -3,21 +3,23 @@ module SolidusSubscriptions module ProcessingErrorHandlers class RailsLogger - def self.call(exception) - new(exception).call + def self.call(exception, installment = nil) + new(exception, installment).call end - def initialize(exception) + def initialize(exception, installment = nil) @exception = exception + @installment = installment end def call - Rails.logger.error exception.message + Rails.logger.error("Error processing installment with ID=#{installment.id}:") if installment + Rails.logger.error(exception.message) end private - attr_reader :exception + attr_reader :exception, :installment end end end diff --git a/spec/jobs/solidus_subscriptions/process_installment_job_spec.rb b/spec/jobs/solidus_subscriptions/process_installment_job_spec.rb index 7211cfe..767d650 100644 --- a/spec/jobs/solidus_subscriptions/process_installment_job_spec.rb +++ b/spec/jobs/solidus_subscriptions/process_installment_job_spec.rb @@ -12,7 +12,8 @@ RSpec.describe SolidusSubscriptions::ProcessInstallmentJob do end context 'when handling #perform errors' do - it 'by default logs exception data without raising exceptions' do + it 'by default logs exception data without raising exceptions' do # rubocop:disable RSpec/MultipleExpectations + installment = build_stubbed(:installment) checkout = instance_double(SolidusSubscriptions::Checkout).tap do |c| allow(c).to receive(:process).and_raise('test error') end @@ -20,9 +21,10 @@ RSpec.describe SolidusSubscriptions::ProcessInstallmentJob do allow(Rails.logger).to receive(:error) expect { - described_class.perform_now(build_stubbed(:installment)) + described_class.perform_now(installment) }.not_to raise_error + expect(Rails.logger).to have_received(:error).with("Error processing installment with ID=#{installment.id}:").ordered expect(Rails.logger).to have_received(:error).with("test error").ordered end -- cgit v1.2.3