From d06dfef25424c34fa7ac2f9ff0454e3058b1de3b Mon Sep 17 00:00:00 2001 From: PaulDoyle-DEFRA <97455399+PaulDoyle-DEFRA@users.noreply.github.com> Date: Thu, 19 Jan 2023 11:47:47 +0000 Subject: [PATCH 1/3] Handle uncaught exceptions --- .../application_controller.rb | 10 ++++ .../can_add_debug_logging.rb | 50 +++++++++---------- app/views/pages/system_error.html.erb | 8 +++ config/locales/en.yml | 4 ++ 4 files changed, 46 insertions(+), 26 deletions(-) create mode 100644 app/views/pages/system_error.html.erb diff --git a/app/controllers/waste_carriers_engine/application_controller.rb b/app/controllers/waste_carriers_engine/application_controller.rb index b16037068..50b2fe435 100644 --- a/app/controllers/waste_carriers_engine/application_controller.rb +++ b/app/controllers/waste_carriers_engine/application_controller.rb @@ -2,6 +2,8 @@ module WasteCarriersEngine class ApplicationController < ActionController::Base + include WasteCarriersEngine::CanAddDebugLogging + # Prevent CSRF attacks by raising an exception. # For APIs, you may want to use :null_session instead. protect_from_forgery with: :exception @@ -10,5 +12,13 @@ class ApplicationController < ActionController::Base layout "application" default_form_builder GOVUKDesignSystemFormBuilder::FormBuilder + + rescue_from StandardError do |e| + Airbrake.notify e + Rails.logger.error "Unhandled exception: #{e}" + log_transient_registration_details("Uncaught system error", @transient_registration) + redirect_to "/bo/pages/system_error" + end + end end diff --git a/app/services/concerns/waste_carriers_engine/can_add_debug_logging.rb b/app/services/concerns/waste_carriers_engine/can_add_debug_logging.rb index d7c557521..fdca0d558 100644 --- a/app/services/concerns/waste_carriers_engine/can_add_debug_logging.rb +++ b/app/services/concerns/waste_carriers_engine/can_add_debug_logging.rb @@ -4,39 +4,37 @@ module WasteCarriersEngine module CanAddDebugLogging extend ActiveSupport::Concern - # rubocop:disable Metrics/MethodLength, Metrics/CyclomaticComplexity, Metrics/PerceivedComplexity + # rubocop:disable Metrics/MethodLength, Metrics/CyclomaticComplexity, Metrics/PerceivedComplexity, Metrics/AbcSize def log_transient_registration_details(description, transient_registration) return unless FeatureToggle.active?(:additional_debug_logging) - error = if transient_registration.nil? - StandardError.new("#{description}: transient_registration is nil") - else - StandardError.new( - "#{description}: " \ - "type: #{transient_registration.class}, " \ - "reg_identifier #{transient_registration.reg_identifier}, " \ - "from_magic_link: #{from_magic_link(transient_registration)}, " \ - "workflow_state: #{transient_registration.workflow_state}, " \ - "workflow_history: #{transient_registration.workflow_history}, " \ - "tier: #{transient_registration.tier}, " \ - "account_email: #{transient_registration.account_email}, " \ - "expires_on: #{transient_registration.expires_on}, " \ - "renew_token: #{renew_token(transient_registration)}, " \ - "metaData.route: #{transient_registration.metaData.route}, " \ - "created_at: #{transient_registration.created_at}, " \ - "orders: #{transient_registration.finance_details&.orders}, " \ - "payments: #{transient_registration.finance_details&.payments}" - ) - end - Airbrake.notify(error, reg_identifier: transient_registration.reg_identifier) if defined?(Airbrake) - Rails.logger.warn error + details = if transient_registration.nil? + { transient_registration: nil } + else + { type: transient_registration.class.to_s, + reg_identifier: transient_registration.reg_identifier, + from_magic_link: from_magic_link(transient_registration), + workflow_state: transient_registration.workflow_state, + workflow_history: transient_registration.workflow_history.to_s, + tier: transient_registration.tier, + account_email: transient_registration.account_email, + expires_on: transient_registration.expires_on, + renew_token: renew_token(transient_registration), + "metaData.route": transient_registration.metaData.route, + created_at: transient_registration.created_at, + orders: transient_registration.finance_details&.orders.to_s, + payments: transient_registration.finance_details&.payments.to_s } + end + Airbrake.notify(StandardError.new(description), details) if defined?(Airbrake) + Rails.logger.warn "#{description}: #{details}" # Handle any exceptions which arise while logging rescue StandardError => e - Airbrake.notify(e, reg_identifier: transient_registration.reg_identifier) if defined?(Airbrake) - Rails.logger.warn "Error writing transient registration details to the log: #{e}" + Airbrake.notify(e, reg_identifier: transient_registration&.reg_identifier) if defined?(Airbrake) + Rails.logger.warn "Error writing debugging information for transient registration " \ + "#{transient_registration&.reg_identifier} to the log: #{e}" end - # rubocop:enable Metrics/MethodLength, Metrics/CyclomaticComplexity, Metrics/PerceivedComplexity + # rubocop:enable Metrics/MethodLength, Metrics/CyclomaticComplexity, Metrics/PerceivedComplexity, Metrics/AbcSize private diff --git a/app/views/pages/system_error.html.erb b/app/views/pages/system_error.html.erb new file mode 100644 index 000000000..565a0d3f9 --- /dev/null +++ b/app/views/pages/system_error.html.erb @@ -0,0 +1,8 @@ +<% content_for :title, I18n.t(".system_error_title") %> + +
+
+

<%= I18n.t(".system_error_heading") %>

+

<%= I18n.t(".system_error_text") %>

+
+
diff --git a/config/locales/en.yml b/config/locales/en.yml index 030852c94..7fd9ab7f8 100644 --- a/config/locales/en.yml +++ b/config/locales/en.yml @@ -44,6 +44,10 @@ en: other: "%{count} addresses found" # Custom error pages + system_error_title: System error + system_error_heading: A system error has occurred + system_error_text: We are unable to complete this request at this time. Please try again later. + invalid_reg_identifier_title: Cannot find page invalid_reg_identifier_heading: We cannot find that page invalid_reg_identifier_text: If you have recently completed a registration then check your email. From c6dd47d07808888d13a3697b8895d9f23776b873 Mon Sep 17 00:00:00 2001 From: PaulDoyle-DEFRA <97455399+PaulDoyle-DEFRA@users.noreply.github.com> Date: Thu, 19 Jan 2023 14:30:51 +0000 Subject: [PATCH 2/3] Improve unit test coverage for deep debugging --- .../registration_completion_service_spec.rb | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/spec/services/waste_carriers_engine/registration_completion_service_spec.rb b/spec/services/waste_carriers_engine/registration_completion_service_spec.rb index f6df1d43f..ff80b465e 100644 --- a/spec/services/waste_carriers_engine/registration_completion_service_spec.rb +++ b/spec/services/waste_carriers_engine/registration_completion_service_spec.rb @@ -341,6 +341,16 @@ module WasteCarriersEngine expect(Airbrake).to have_received(:notify).at_least(:once) end end + + context "when the additional logging raises an exception" do + before { allow(transient_registration).to receive(:metaData).and_raise(StandardError) } + + it "catches the exception and notifies Airbrake anyway" do + described_class.new.log_transient_registration_details("foo", transient_registration) + + expect(Airbrake).to have_received(:notify) + end + end end end end From 88b6daea8e2b6b046d4ddf36797a6fb24f69f308 Mon Sep 17 00:00:00 2001 From: PaulDoyle-DEFRA <97455399+PaulDoyle-DEFRA@users.noreply.github.com> Date: Thu, 19 Jan 2023 16:38:33 +0000 Subject: [PATCH 3/3] Handle Airbrake.notify exceptions and move can_add_debug_logging unit tests to a separate file --- .../can_add_debug_logging.rb | 14 +++-- .../can_add_debug_logging_spec.rb | 55 +++++++++++++++++++ .../registration_completion_service_spec.rb | 50 ----------------- 3 files changed, 65 insertions(+), 54 deletions(-) create mode 100644 spec/services/concerns/waste_carriers_engine/can_add_debug_logging_spec.rb diff --git a/app/services/concerns/waste_carriers_engine/can_add_debug_logging.rb b/app/services/concerns/waste_carriers_engine/can_add_debug_logging.rb index fdca0d558..aff1f698d 100644 --- a/app/services/concerns/waste_carriers_engine/can_add_debug_logging.rb +++ b/app/services/concerns/waste_carriers_engine/can_add_debug_logging.rb @@ -25,14 +25,20 @@ def log_transient_registration_details(description, transient_registration) orders: transient_registration.finance_details&.orders.to_s, payments: transient_registration.finance_details&.payments.to_s } end - Airbrake.notify(StandardError.new(description), details) if defined?(Airbrake) + Airbrake.notify(StandardError.new(description), details) Rails.logger.warn "#{description}: #{details}" # Handle any exceptions which arise while logging rescue StandardError => e - Airbrake.notify(e, reg_identifier: transient_registration&.reg_identifier) if defined?(Airbrake) - Rails.logger.warn "Error writing debugging information for transient registration " \ - "#{transient_registration&.reg_identifier} to the log: #{e}" + # Allow for the possibility that Airbrake.notify might raise an exception + begin + Airbrake.notify(e, reg_identifier: transient_registration&.reg_identifier) + rescue StandardError + Rails.logger.warn "Message not sent to Airbrake due to exception: #{e}" + ensure + Rails.logger.warn "Error writing debugging information for transient registration " \ + "#{transient_registration&.reg_identifier} to the log: #{e}" + end end # rubocop:enable Metrics/MethodLength, Metrics/CyclomaticComplexity, Metrics/PerceivedComplexity, Metrics/AbcSize diff --git a/spec/services/concerns/waste_carriers_engine/can_add_debug_logging_spec.rb b/spec/services/concerns/waste_carriers_engine/can_add_debug_logging_spec.rb new file mode 100644 index 000000000..0e208eb81 --- /dev/null +++ b/spec/services/concerns/waste_carriers_engine/can_add_debug_logging_spec.rb @@ -0,0 +1,55 @@ +# frozen_string_literal: true + +require "rails_helper" + +class DebugClass + include WasteCarriersEngine::CanAddDebugLogging +end + +module WasteCarriersEngine + RSpec.describe CanAddDebugLogging do + + describe "#log_transient_registration_details" do + + let(:transient_registration) { create(:new_registration, :has_required_data) } + + subject(:log_details) { DebugClass.new.log_transient_registration_details("foo", transient_registration) } + + before do + allow(Airbrake).to receive(:notify) + allow(FeatureToggle).to receive(:active?).with(:additional_debug_logging).and_return true + end + + it "logs an error" do + log_details + expect(Airbrake).to have_received(:notify) + end + + context "with a nil transient_registration" do + before { allow(transient_registration).to receive(:nil?).and_return(true) } + + it "logs an error" do + log_details + expect(Airbrake).to have_received(:notify) + end + end + + context "when the additional logging raises an exception" do + before { allow(transient_registration).to receive(:metaData).and_raise(StandardError) } + + it "catches the exception and notifies Airbrake anyway" do + log_details + expect(Airbrake).to have_received(:notify) + end + end + + context "when the call to Airbrake fails" do + before { allow(Airbrake).to receive(:notify).and_raise(StandardError) } + + it "completes without raising another exception" do + expect { log_details }.not_to raise_error + end + end + end + end +end diff --git a/spec/services/waste_carriers_engine/registration_completion_service_spec.rb b/spec/services/waste_carriers_engine/registration_completion_service_spec.rb index ff80b465e..27b0581e1 100644 --- a/spec/services/waste_carriers_engine/registration_completion_service_spec.rb +++ b/spec/services/waste_carriers_engine/registration_completion_service_spec.rb @@ -302,56 +302,6 @@ module WasteCarriersEngine expect(OrderItemLog.count).to be_zero end end - - context "with temporary additional debugging" do - - before do - allow(Airbrake).to receive(:notify) - allow(FeatureToggle).to receive(:active?).with(:additional_debug_logging).and_return true - allow(FeatureToggle).to receive(:active?).with(:govpay_payments).and_return true - end - - it "logs an error" do - described_class.new.log_transient_registration_details("foo", transient_registration) - - expect(Airbrake).to have_received(:notify) - end - - context "with a nil transient_registration" do - before { allow(transient_registration).to receive(:nil?).and_return(true) } - - it "logs an error" do - described_class.new.log_transient_registration_details("foo", transient_registration) - - expect(Airbrake).to have_received(:notify) - end - end - - context "when activating the registration raises an exception" do - let(:registration_activation_service) { instance_double(RegistrationActivationService) } - - before do - allow(RegistrationActivationService).to receive(:new).and_return(registration_activation_service) - allow(registration_activation_service).to receive(:run).and_raise(StandardError) - end - - it "logs an error" do - described_class.run(transient_registration) - - expect(Airbrake).to have_received(:notify).at_least(:once) - end - end - - context "when the additional logging raises an exception" do - before { allow(transient_registration).to receive(:metaData).and_raise(StandardError) } - - it "catches the exception and notifies Airbrake anyway" do - described_class.new.log_transient_registration_details("foo", transient_registration) - - expect(Airbrake).to have_received(:notify) - end - end - end end end end