Updated submission failure notification code and wrote some tests

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")

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

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,15 +366,24 @@ 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',
           { match_requests_on: %i[method uri body], erb: true }
         ) 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(

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