From 6a19448e1d50477afd27316f840c031752ecae21 Mon Sep 17 00:00:00 2001 From: Joshua Drumm Date: Fri, 6 Sep 2024 13:11:20 -0400 Subject: [PATCH] Updated submission failure notification code and wrote some tests --- app/sidekiq/hca/ezr_submission_job.rb | 11 ++- lib/form1010_ezr/service.rb | 32 ++++++--- spec/lib/form1010_ezr/service_spec.rb | 75 +++++++++++++++++++-- spec/sidekiq/hca/ezr_submission_job_spec.rb | 25 +++++-- 4 files changed, 115 insertions(+), 28 deletions(-) diff --git a/app/sidekiq/hca/ezr_submission_job.rb b/app/sidekiq/hca/ezr_submission_job.rb index 1b2eccf35e4..42e2ae51aa9 100644 --- a/app/sidekiq/hca/ezr_submission_job.rb +++ b/app/sidekiq/hca/ezr_submission_job.rb @@ -12,11 +12,10 @@ class EzrSubmissionJob sidekiq_options retry: 14 sidekiq_retries_exhausted do |msg, _e| - log_submission_failure(decrypt_form(msg['args'][0])) - end - - def self.log_submission_failure(parsed_form) - Form1010Ezr::Service.new(nil).log_submission_failure(parsed_form) + Form1010Ezr::Service.new(nil).log_submission_failure( + decrypt_form(msg['args'][0]), + retries_exhausted: true + ) end def self.decrypt_form(encrypted_form) @@ -29,7 +28,7 @@ def perform(encrypted_form, user_uuid) Form1010Ezr::Service.new(user).submit_sync(parsed_form) rescue VALIDATION_ERROR => e - self.class.log_submission_failure(parsed_form) + Form1010Ezr::Service.new(nil).log_submission_failure(parsed_form) log_exception_to_sentry(e) rescue StatsD.increment("#{Form1010Ezr::Service::STATSD_KEY_PREFIX}.async.retries") diff --git a/lib/form1010_ezr/service.rb b/lib/form1010_ezr/service.rb index c87e9cabda4..49d9233c7eb 100644 --- a/lib/form1010_ezr/service.rb +++ b/lib/form1010_ezr/service.rb @@ -41,7 +41,11 @@ def submit_sync(parsed_form) end # Log the 'formSubmissionId' for successful submissions - Rails.logger.info("SubmissionID=#{res[:formSubmissionId]}") + Rails.logger.info( + '1010EZR successfully submitted', + submission_id: res[:formSubmissionId], + veteran_initials: veteran_initials(parsed_form) + ) res rescue => e @@ -60,24 +64,22 @@ def submit_form(parsed_form) log_and_raise_error(e, parsed_form) end - def log_submission_failure(parsed_form) - StatsD.increment("#{Form1010Ezr::Service::STATSD_KEY_PREFIX}.failed_wont_retry") + def log_submission_failure(parsed_form, retries_exhausted: false) + StatsD.increment("#{Form1010Ezr::Service::STATSD_KEY_PREFIX}.failed#{'_wont_retry' if retries_exhausted}") if parsed_form.present? PersonalInformationLog.create!( data: parsed_form, - error_class: 'Form1010Ezr FailedWontRetry' + error_class: "Form1010Ezr Failed#{'WontRetry' if retries_exhausted}" ) + failure_message = "1010EZR #{'total ' if retries_exhausted}failure" + log_message_to_sentry( - '1010EZR total failure', + failure_message, :error, - { - first_initial: parsed_form.dig('veteranFullName', 'first')&.chr || 'no initial provided', - middle_initial: parsed_form.dig('veteranFullName', 'middle')&.chr || 'no initial provided', - last_initial: parsed_form.dig('veteranFullName', 'last')&.chr || 'no initial provided' - }, - ezr: :total_failure + veteran_initials(parsed_form), + ezr: retries_exhausted ? :total_failure : :failure ) end end @@ -174,5 +176,13 @@ def log_and_raise_error(error, form) Rails.logger.error "10-10EZR form submission failed: #{error.message}" raise error end + + def veteran_initials(parsed_form) + { + first_initial: parsed_form.dig('veteranFullName', 'first')&.chr || 'no initial provided', + middle_initial: parsed_form.dig('veteranFullName', 'middle')&.chr || 'no initial provided', + last_initial: parsed_form.dig('veteranFullName', 'last')&.chr || 'no initial provided' + } + end end end diff --git a/spec/lib/form1010_ezr/service_spec.rb b/spec/lib/form1010_ezr/service_spec.rb index 61a1159dc89..9c6a3f2b02f 100644 --- a/spec/lib/form1010_ezr/service_spec.rb +++ b/spec/lib/form1010_ezr/service_spec.rb @@ -62,6 +62,13 @@ def ezr_form_with_attachments ) end + def expect_personal_info_log(message) + pii_log = PersonalInformationLog.last + + expect(pii_log.error_class).to eq(message) + expect(pii_log.data).to eq(form) + end + describe '#add_financial_flag' do context 'when the form has veteran gross income' do let(:parsed_form) do @@ -86,17 +93,18 @@ def ezr_form_with_attachments describe '#post_fill_required_fields' do it 'Adds required fields in the Enrollment System API to the form object', - run_at: 'Fri, 08 Feb 2019 02:50:45 GMT' do + run_at: 'Fri, 08 Feb 2019 02:50:45 GMT' do VCR.use_cassette( 'hca/ee/lookup_user', VCR::MATCH_EVERYTHING.merge(erb: true) ) do - expect(form['isEssentialAcaCoverage']).to eq(nil) - expect(form['vaMedicalFacility']).to eq(nil) + expect(form.keys).to_not include('isEssentialAcaCoverage', 'vaMedicalFacility') service.send(:post_fill_required_fields, form) expect(form.keys).to include('isEssentialAcaCoverage', 'vaMedicalFacility') + expect(form['isEssentialAcaCoverage']).to eq(false) + expect(form['vaMedicalFacility']).to eq('988') end end end @@ -156,6 +164,54 @@ def ezr_form_with_attachments end end + describe '#log_submission_failure' do + context "when 'parsed_form' is present" do + context "when 'retries_exhausted' is false" do + it "increments StatsD, creates a 'PersonalInformationLog' record, and logs a failure message to sentry" do + # The names for these errors will not include 'total' or 'wont_retry' as they are not for total failures + allow(StatsD).to receive(:increment) + expect(StatsD).to receive(:increment).with('api.1010ezr.failed') + expect_any_instance_of(SentryLogging).to receive(:log_message_to_sentry).with( + '1010EZR failure', + :error, + { + first_initial: 'F', + middle_initial: 'M', + last_initial: 'Z' + }, + ezr: :failure + ) + + described_class.new(nil).log_submission_failure(form) + + expect_personal_info_log('Form1010Ezr Failed') + end + end + + context "when 'retries_exhausted' is true" do + it "increments StatsD, creates a 'PersonalInformationLog' record, and logs a TOTAL failure message to sentry" do + allow(StatsD).to receive(:increment) + + expect(StatsD).to receive(:increment).with('api.1010ezr.failed_wont_retry') + expect_any_instance_of(SentryLogging).to receive(:log_message_to_sentry).with( + '1010EZR total failure', + :error, + { + first_initial: 'F', + middle_initial: 'M', + last_initial: 'Z' + }, + ezr: :total_failure + ) + + described_class.new(nil).log_submission_failure(form, retries_exhausted: true) + + expect_personal_info_log('Form1010Ezr FailedWontRetry') + end + end + end + end + describe '#submit_form' do it 'submits the ezr with a background job', run_at: 'Tue, 21 Nov 2023 20:42:44 GMT' do VCR.use_cassette( @@ -310,7 +366,8 @@ def ezr_form_with_attachments end end - it 'logs the submission id, payload size, and individual attachment sizes in descending order (if applicable)', + it "logs the submission id, user's initials, payload size, and individual attachment sizes in descending "\ + 'order (if applicable)', run_at: 'Wed, 17 Jul 2024 18:17:30 GMT' do VCR.use_cassette( 'form1010_ezr/authorized_submit_with_attachments', @@ -318,7 +375,15 @@ def ezr_form_with_attachments ) do submission_response = service.submit_sync(ezr_form_with_attachments) - expect(Rails.logger).to have_received(:info).with("SubmissionID=#{submission_response[:formSubmissionId]}") + expect(Rails.logger).to have_received(:info).with( + '1010EZR successfully submitted', + submission_id: submission_response[:formSubmissionId], + veteran_initials: { + first_initial: 'F', + middle_initial: 'M', + last_initial: 'Z' + } + ) expect(Rails.logger).to have_received(:info).with('Payload for submitted 1010EZR: ' \ 'Body size of 362 KB with 2 attachment(s)') expect(Rails.logger).to have_received(:info).with( diff --git a/spec/sidekiq/hca/ezr_submission_job_spec.rb b/spec/sidekiq/hca/ezr_submission_job_spec.rb index b86465558de..a65715a2a33 100644 --- a/spec/sidekiq/hca/ezr_submission_job_spec.rb +++ b/spec/sidekiq/hca/ezr_submission_job_spec.rb @@ -12,18 +12,31 @@ end let(:ezr_service) { double } - describe 'when job has failed' do + describe 'when retries are exhausted' do let(:msg) do { 'args' => [encrypted_form, nil] } end - it 'passes unencrypted form to 1010ezr service' do - expect_any_instance_of(Form1010Ezr::Service).to receive(:log_submission_failure).with( - form - ) - described_class.new.sidekiq_retries_exhausted_block.call(msg) + it "increments StatsD, creates a 'PersonalInformationLog' record, and logs a failure message to sentry" do + described_class.within_sidekiq_retries_exhausted_block(msg) do + expect(StatsD).to receive(:increment).with('api.1010ezr.failed_wont_retry') + expect_any_instance_of(SentryLogging).to receive(:log_message_to_sentry).with( + '1010EZR total failure', + :error, + { + first_initial: 'F', + middle_initial: 'M', + last_initial: 'Z' + }, + ezr: :total_failure + ) + end + + pii_log = PersonalInformationLog.last + expect(pii_log.error_class).to eq('Form1010Ezr FailedWontRetry') + expect(pii_log.data).to eq(form) end end