[DBEX] log and monitor evidence upload failure email events (#19097)

app/sidekiq/evss/disability_compensation_form/form526_document_upload_failure_email.rb

@@ -1,11 +1,13 @@
 # frozen_string_literal: true
 
 require 'va_notify/service'
+require 'zero_silent_failures/monitor'
 
 module EVSS
   module DisabilityCompensationForm
     class Form526DocumentUploadFailureEmail < Job
       STATSD_METRIC_PREFIX = 'api.form_526.veteran_notifications.document_upload_failure_email'
+      ZSF_DD_TAG_FUNCTION = '526_evidence_upload_failure_email_queuing'
 
       # retry for one day
       sidekiq_options retry: 14
@@ -17,6 +19,11 @@ class Form526DocumentUploadFailureEmail < Job
         timestamp = Time.now.utc
         form526_submission_id, supporting_evidence_attachment_guid = msg['args']
 
+        log_info = { job_id:, timestamp:, form526_submission_id:, error_class:, error_message:,
+                     supporting_evidence_attachment_guid: }
+
+        Rails.logger.warn('Form526DocumentUploadFailureEmail retries exhausted', log_info)
+
         # Job status records are upserted in the JobTracker module
         # when the retryable_error_handler is called
         form_job_status = Form526JobStatus.find_by(job_id:)
@@ -33,20 +40,6 @@ class Form526DocumentUploadFailureEmail < Job
           status: Form526JobStatus::STATUS[:exhausted],
           bgjob_errors: bgjob_errors.merge(new_error)
         )
-
-        Rails.logger.warn(
-          'Form526DocumentUploadFailureEmail retries exhausted',
-          {
-            job_id:,
-            timestamp:,
-            form526_submission_id:,
-            error_class:,
-            error_message:,
-            supporting_evidence_attachment_guid:
-          }
-        )
-
-        StatsD.increment("#{STATSD_METRIC_PREFIX}.exhausted")
       rescue => e
         Rails.logger.error(
           'Failure in Form526DocumentUploadFailureEmail#sidekiq_retries_exhausted',
@@ -62,17 +55,28 @@ class Form526DocumentUploadFailureEmail < Job
           }
         )
         raise e
+      ensure
+        StatsD.increment("#{STATSD_METRIC_PREFIX}.exhausted")
+
+        cl = caller_locations.first
+        call_location = ZeroSilentFailures::Monitor::CallLocation.new(ZSF_DD_TAG_FUNCTION, cl.path, cl.lineno)
+        zsf_monitor = ZeroSilentFailures::Monitor.new(Form526Submission::ZSF_DD_TAG_SERVICE)
+        user_account_id = begin
+          Form526Submission.find(form526_submission_id).user_account_id
+        rescue
+          nil
+        end
+
+        zsf_monitor.log_silent_failure(log_info, user_account_id, call_location:)
       end
 
       def perform(form526_submission_id, supporting_evidence_attachment_guid)
         super(form526_submission_id)
+
         submission = Form526Submission.find(form526_submission_id)
 
         with_tracking('Form526DocumentUploadFailureEmail', submission.saved_claim_id, form526_submission_id) do
-          @notify_client ||= VaNotify::Service.new(Settings.vanotify.services.benefits_disability.api_key)
           send_notification_mailer(submission, supporting_evidence_attachment_guid)
-
-          StatsD.increment("#{STATSD_METRIC_PREFIX}.success")
         end
       rescue => e
         retryable_error_handler(e)
@@ -83,32 +87,42 @@ def perform(form526_submission_id, supporting_evidence_attachment_guid)
       def send_notification_mailer(submission, supporting_evidence_attachment_guid)
         form_attachment = SupportingEvidenceAttachment.find_by!(guid: supporting_evidence_attachment_guid)
 
-        # We need to obscure the original filename since it may contain PII
+        # We need to obscure the original filename as it may contain PII
         obscured_filename = form_attachment.obscured_filename
-
         email_address = submission.veteran_email_address
         first_name = submission.get_first_name
         date_submitted = submission.format_creation_time_for_mailers
-        @notify_client.send_email(
+
+        notify_service_bd = Settings.vanotify.services.benefits_disability
+        notify_client = VaNotify::Service.new(notify_service_bd.api_key)
+        template_id = notify_service_bd.template_id.form526_document_upload_failure_notification_template_id
+
+        notify_response = notify_client.send_email(
           email_address:,
-          template_id: mailer_template_id,
+          template_id:,
           personalisation: { first_name:, filename: obscured_filename, date_submitted: }
         )
 
-        Rails.logger.info(
-          'Form526DocumentUploadFailureEmail notification dispatched',
-          {
-            obscured_filename:,
-            form526_submission_id: submission.id,
-            supporting_evidence_attachment_guid:,
-            timestamp: Time.now.utc
-          }
-        )
+        log_info = { obscured_filename:, form526_submission_id: submission.id,
+                     supporting_evidence_attachment_guid:, timestamp: Time.now.utc }
+
+        log_mailer_dispatch(log_info, submission, notify_response)
       end
 
-      def mailer_template_id
-        Settings.vanotify.services
-                .benefits_disability.template_id.form526_document_upload_failure_notification_template_id
+      def log_mailer_dispatch(log_info, submission, email_response = {})
+        StatsD.increment("#{STATSD_METRIC_PREFIX}.success")
+
+        Rails.logger.info('Form526DocumentUploadFailureEmail notification dispatched', log_info)
+
+        cl = caller_locations.first
+        call_location = ZeroSilentFailures::Monitor::CallLocation.new(ZSF_DD_TAG_FUNCTION, cl.path, cl.lineno)
+        zsf_monitor = ZeroSilentFailures::Monitor.new(Form526Submission::ZSF_DD_TAG_SERVICE)
+
+        zsf_monitor.log_silent_failure_avoided(
+          log_info.merge(email_confirmation_id: email_response&.id),
+          submission.user_account_id,
+          call_location:
+        )
       end
 
       def retryable_error_handler(error)

app/sidekiq/evss/disability_compensation_form/submit_uploads.rb

@@ -1,9 +1,12 @@
 # frozen_string_literal: true
 
+require 'zero_silent_failures/monitor'
+
 module EVSS
   module DisabilityCompensationForm
     class SubmitUploads < Job
       STATSD_KEY_PREFIX = 'worker.evss.submit_form526_upload'
+      ZSF_DD_TAG_FUNCTION = '526_evidence_upload_failure_email_queuing'
 
       # retry for one day
       sidekiq_options retry: 14
@@ -14,6 +17,9 @@ class SubmitUploads < Job
         error_message = msg['error_message']
         timestamp = Time.now.utc
         form526_submission_id = msg['args'].first
+        log_info = { job_id:, error_class:, error_message:, timestamp:, form526_submission_id: }
+
+        Rails.logger.warn('Submit Form 526 Upload Retries exhausted', log_info)
 
         form_job_status = Form526JobStatus.find_by(job_id:)
         bgjob_errors = form_job_status.bgjob_errors || {}
@@ -31,6 +37,8 @@ class SubmitUploads < Job
           bgjob_errors: bgjob_errors.merge(new_error)
         )
 
+        StatsD.increment("#{STATSD_KEY_PREFIX}.exhausted")
+
         if Flipper.enabled?(:form526_send_document_upload_failure_notification)
           # Extract original job arguments
           # (form526_submission_id already extracted above;
@@ -41,14 +49,18 @@ class SubmitUploads < Job
           guid = upload_data['confirmationCode']
           Form526DocumentUploadFailureEmail.perform_async(form526_submission_id, guid)
         end
+      rescue => e
+        cl = caller_locations.first
+        call_location = ZeroSilentFailures::Monitor::CallLocation.new(ZSF_DD_TAG_FUNCTION, cl.path, cl.lineno)
+        zsf_monitor = ZeroSilentFailures::Monitor.new(Form526Submission::ZSF_DD_TAG_SERVICE)
+        user_account_id = begin
+          Form526Submission.find(form526_submission_id).user_account_id
+        rescue
+          nil
+        end
 
-        StatsD.increment("#{STATSD_KEY_PREFIX}.exhausted")
+        zsf_monitor.log_silent_failure(log_info, user_account_id, call_location:)
 
-        ::Rails.logger.warn(
-          'Submit Form 526 Upload Retries exhausted',
-          { job_id:, error_class:, error_message:, timestamp:, form526_submission_id: }
-        )
-      rescue => e
         ::Rails.logger.error(
           'Failure in SubmitUploads#sidekiq_retries_exhausted',
           {

spec/sidekiq/evss/disability_compensation_form/form526_document_upload_failure_email_spec.rb

@@ -85,13 +85,18 @@
         end
       end
 
-      it 'increments a Statsd metric' do
-        # allow(notification_client).to receive(:send_email)
+      it 'increments StatsD success & silent failure avoided metrics' do
         expect do
           subject.perform_async(form526_submission.id, form_attachment.guid)
           subject.drain
         end.to trigger_statsd_increment(
           'api.form_526.veteran_notifications.document_upload_failure_email.success'
+        ).and trigger_statsd_increment(
+          'silent_failure_avoided_no_confirmation',
+          tags: [
+            'service:disability-application',
+            'function:526_evidence_upload_failure_email_queuing'
+          ]
         )
       end
 
@@ -121,7 +126,7 @@
       allow(notification_client).to receive(:send_email)
     end
 
-    it 'increments a StatsD exhaustion metric, logs to the Rails logger and updates the job status' do
+    it 'increments StatsD exhaustion & silent failure metrics, logs to the Rails logger and updates the job status' do
       Timecop.freeze(exhaustion_time) do
         described_class.within_sidekiq_retries_exhausted_block(retry_params) do
           expect(Rails.logger).to receive(:warn).with(
@@ -135,9 +140,18 @@
               supporting_evidence_attachment_guid: form_attachment.guid
             }
           ).and_call_original
+
           expect(StatsD).to receive(:increment).with(
             'api.form_526.veteran_notifications.document_upload_failure_email.exhausted'
-          )
+          ).ordered
+
+          expect(StatsD).to receive(:increment).with(
+            'silent_failure',
+            tags: [
+              'service:disability-application',
+              'function:526_evidence_upload_failure_email_queuing'
+            ]
+          ).ordered
         end
 
         form526_job_status.reload

spec/sidekiq/evss/disability_compensation_form/submit_uploads_spec.rb

@@ -23,9 +23,10 @@
            saved_claim_id: saved_claim.id,
            submitted_claim_id: '600130094')
   end
+  let(:form526_job_status) { create(:form526_job_status, :retryable_error, form526_submission: submission, job_id: 1) }
+  let(:upload_data) { [submission.form[Form526Submission::FORM_526_UPLOADS].first] }
 
   describe 'perform' do
-    let(:upload_data) { [submission.form[Form526Submission::FORM_526_UPLOADS].first] }
     let(:document_data) { double(:document_data, valid?: true) }
 
     context 'when file_data exists' do
@@ -65,15 +66,6 @@
       end
 
       context 'when all retries are exhausted' do
-        let!(:form526_job_status) do
-          create(
-            :form526_job_status,
-            :retryable_error,
-            form526_submission: submission,
-            job_id: 1
-          )
-        end
-
         let(:file) { Rack::Test::UploadedFile.new('spec/fixtures/files/sm_file1.jpg', 'image/jpg') }
         let!(:attachment) do
           sea = SupportingEvidenceAttachment.new(guid: upload_data.first['confirmationCode'])
@@ -156,9 +148,6 @@
 
   context 'catastrophic failure state' do
     describe 'when all retries are exhausted' do
-      let!(:form526_submission) { create(:form526_submission) }
-      let!(:form526_job_status) { create(:form526_job_status, :retryable_error, form526_submission:, job_id: 1) }
-
       it 'updates a StatsD counter and updates the status on an exhaustion event' do
         subject.within_sidekiq_retries_exhausted_block({ 'jid' => form526_job_status.job_id }) do
           expect(StatsD).to receive(:increment).with("#{subject::STATSD_KEY_PREFIX}.exhausted")
@@ -168,5 +157,38 @@
         expect(form526_job_status.status).to eq(Form526JobStatus::STATUS[:exhausted])
       end
     end
+
+    describe 'when an error occurs during exhaustion handling and FailureEmail fails to enqueue' do
+      let!(:zsf_tag) { Form526Submission::ZSF_DD_TAG_SERVICE }
+      let!(:zsf_monitor) { ZeroSilentFailures::Monitor.new(zsf_tag) }
+      let!(:failure_email) { EVSS::DisabilityCompensationForm::Form526DocumentUploadFailureEmail }
+
+      before do
+        Flipper.enable(:form526_send_document_upload_failure_notification)
+        allow(ZeroSilentFailures::Monitor).to receive(:new).with(zsf_tag).and_return(zsf_monitor)
+      end
+
+      it 'logs a silent failure' do
+        expect(zsf_monitor).to receive(:log_silent_failure).with(
+          {
+            job_id: form526_job_status.job_id,
+            error_class: nil,
+            error_message: 'An error occured',
+            timestamp: instance_of(Time),
+            form526_submission_id: submission.id
+          },
+          nil,
+          call_location: instance_of(ZeroSilentFailures::Monitor::CallLocation)
+        )
+
+        args = { 'jid' => form526_job_status.job_id, 'args' => [submission.id, upload_data] }
+
+        expect do
+          subject.within_sidekiq_retries_exhausted_block(args) do
+            allow(failure_email).to receive(:perform_async).and_raise(StandardError, 'Simulated error')
+          end
+        end.to raise_error(StandardError, 'Simulated error')
+      end
+    end
   end
 end