Add phone metadata to telephony logging

app/controllers/users/two_factor_authentication_controller.rb

@@ -272,19 +272,24 @@ def send_user_otp(method)
       end
 
       current_user.create_direct_otp
-      params = {
+      otp_params = {
         to: phone_to_deliver_to,
         otp: current_user.direct_otp,
         expiration: TwoFactorAuthenticatable::DIRECT_OTP_VALID_FOR_MINUTES,
         channel: method.to_sym,
         domain: IdentityConfig.store.domain_name,
         country_code: parsed_phone.country,
+        extra_metadata: {
+          area_code: parsed_phone.area_code,
+          phone_fingerprint: Pii::Fingerprinter.fingerprint(parsed_phone.e164),
+          resend: params.dig(:otp_delivery_selection_form, :resend),
+        },
       }
 
       if UserSessionContext.authentication_or_reauthentication_context?(context)
-        Telephony.send_authentication_otp(**params)
+        Telephony.send_authentication_otp(**otp_params)
       else
-        Telephony.send_confirmation_otp(**params)
+        Telephony.send_confirmation_otp(**otp_params)
       end
     end
 

app/services/idv/send_phone_confirmation_otp.rb

@@ -60,6 +60,11 @@ def send_otp
         channel: delivery_method,
         domain: IdentityConfig.store.domain_name,
         country_code: parsed_phone.country,
+        extra_metadata: {
+          area_code: parsed_phone.area_code,
+          phone_fingerprint: Pii::Fingerprinter.fingerprint(parsed_phone.e164),
+          resend: nil,
+        },
       )
       otp_sent_response
     end

lib/telephony.rb

@@ -43,25 +43,29 @@ def self.config
     @config
   end
 
-  def self.send_authentication_otp(to:, otp:, expiration:, channel:, domain:, country_code:)
+  def self.send_authentication_otp(to:, otp:, expiration:, channel:, domain:, country_code:,
+                                   extra_metadata:)
     OtpSender.new(
       to: to,
       otp: otp,
       expiration: expiration,
       channel: channel,
       domain: domain,
       country_code: country_code,
+      extra_metadata: extra_metadata,
     ).send_authentication_otp
   end
 
-  def self.send_confirmation_otp(to:, otp:, expiration:, channel:, domain:, country_code:)
+  def self.send_confirmation_otp(to:, otp:, expiration:, channel:, domain:, country_code:,
+                                 extra_metadata:)
     OtpSender.new(
       to: to,
       otp: otp,
       expiration: expiration,
       channel: channel,
       domain: domain,
       country_code: country_code,
+      extra_metadata: extra_metadata,
     ).send_confirmation_otp
   end
 

lib/telephony/otp_sender.rb

@@ -1,14 +1,16 @@
 module Telephony
   class OtpSender
-    attr_reader :recipient_phone, :otp, :expiration, :channel, :domain, :country_code
+    attr_reader :recipient_phone, :otp, :expiration, :channel, :domain, :country_code,
+                :extra_metadata
 
-    def initialize(to:, otp:, expiration:, channel:, domain:, country_code:)
+    def initialize(to:, otp:, expiration:, channel:, domain:, country_code:, extra_metadata:)
       @recipient_phone = to
       @otp = otp
       @expiration = expiration
       @channel = channel.to_sym
       @domain = domain
       @country_code = country_code
+      @extra_metadata = extra_metadata
     end
 
     def send_authentication_otp
@@ -75,11 +77,14 @@ def adapter
     end
 
     def log_response(response, context:)
-      extra = {
-        adapter: Telephony.config.adapter,
-        channel: channel,
-        context: context,
-      }
+      extra = extra_metadata.merge(
+        {
+          adapter: Telephony.config.adapter,
+          channel: channel,
+          context: context,
+          country_code: country_code,
+        },
+      )
       output = response.to_h.merge(extra).to_json
       Telephony.config.logger.info(output)
     end

spec/controllers/test/telephony_controller_spec.rb

@@ -10,6 +10,7 @@
         channel: :sms,
         domain: IdentityConfig.store.domain_name,
         country_code: 'US',
+        extra_metadata: {},
       )
       Telephony.send_authentication_otp(
         to: '(555) 555-5000',
@@ -18,6 +19,7 @@
         channel: :voice,
         domain: IdentityConfig.store.domain_name,
         country_code: 'US',
+        extra_metadata: {},
       )
 
       get :index
@@ -47,6 +49,7 @@
         channel: :sms,
         domain: IdentityConfig.store.domain_name,
         country_code: 'US',
+        extra_metadata: {},
       )
       Telephony.send_authentication_otp(
         to: '(555) 555-5000',
@@ -55,6 +58,7 @@
         channel: :voice,
         domain: IdentityConfig.store.domain_name,
         country_code: 'US',
+        extra_metadata: {},
       )
 
       delete :destroy

spec/controllers/users/two_factor_authentication_controller_spec.rb

@@ -289,13 +289,21 @@ def index
       it 'sends OTP via SMS for sign in' do
         get :send_code, params: otp_delivery_form_sms
 
+        phone = MfaContext.new(subject.current_user).phone_configurations.first.phone
+        parsed_phone = Phonelib.parse(phone)
+
         expect(Telephony).to have_received(:send_authentication_otp).with(
           otp: subject.current_user.direct_otp,
-          to: MfaContext.new(subject.current_user).phone_configurations.first.phone,
+          to: phone,
           expiration: 10,
           channel: :sms,
           domain: IdentityConfig.store.domain_name,
           country_code: 'US',
+          extra_metadata: {
+            area_code: parsed_phone.area_code,
+            phone_fingerprint: Pii::Fingerprinter.fingerprint(parsed_phone.e164),
+            resend: nil,
+          },
         )
         expect(subject.current_user.direct_otp).not_to eq(@old_otp)
         expect(subject.current_user.direct_otp).not_to be_nil
@@ -435,14 +443,21 @@ def index
         get :send_code, params: {
           otp_delivery_selection_form: { otp_delivery_preference: 'voice' },
         }
+        phone = MfaContext.new(subject.current_user).phone_configurations.first.phone
+        parsed_phone = Phonelib.parse(phone)
 
         expect(Telephony).to have_received(:send_authentication_otp).with(
           otp: subject.current_user.direct_otp,
-          to: MfaContext.new(subject.current_user).phone_configurations.first.phone,
+          to: phone,
           expiration: 10,
           channel: :voice,
           domain: IdentityConfig.store.domain_name,
           country_code: 'US',
+          extra_metadata: {
+            area_code: parsed_phone.area_code,
+            phone_fingerprint: Pii::Fingerprinter.fingerprint(parsed_phone.e164),
+            resend: nil,
+          },
         )
         expect(subject.current_user.direct_otp).not_to eq(@old_otp)
         expect(subject.current_user.direct_otp).not_to be_nil
@@ -514,6 +529,7 @@ def index
         sign_in_before_2fa(@user)
         subject.user_session[:context] = 'confirmation'
         subject.user_session[:unconfirmed_phone] = @unconfirmed_phone
+        parsed_phone = Phonelib.parse(@unconfirmed_phone)
 
         allow(Telephony).to receive(:send_confirmation_otp).and_call_original
 
@@ -526,6 +542,11 @@ def index
           channel: :sms,
           domain: IdentityConfig.store.domain_name,
           country_code: 'US',
+          extra_metadata: {
+            area_code: parsed_phone.area_code,
+            phone_fingerprint: Pii::Fingerprinter.fingerprint(parsed_phone.e164),
+            resend: nil,
+          },
         )
       end
 

spec/features/two_factor_authentication/change_factor_spec.rb

@@ -27,6 +27,7 @@
         user = sign_in_and_2fa_user
         phone_configuration = MfaContext.new(user).phone_configurations.first
         old_phone = phone_configuration.phone
+        parsed_phone = Phonelib.parse(old_phone)
 
         travel(IdentityConfig.store.reauthn_window + 1)
         visit manage_phone_path(id: phone_configuration)
@@ -40,7 +41,12 @@
           channel: :sms,
           domain: IdentityConfig.store.domain_name,
           country_code: 'US',
-        )
+          extra_metadata: {
+            area_code: parsed_phone.area_code,
+            phone_fingerprint: Pii::Fingerprinter.fingerprint(parsed_phone.e164),
+            resend: 'true',
+          },
+        ).once
 
         expect(current_path).
           to eq login_two_factor_path(otp_delivery_preference: 'sms')

spec/lib/telephony/otp_sender_spec.rb

@@ -16,6 +16,7 @@
         channel: channel,
         domain: domain,
         country_code: country_code,
+        extra_metadata: { phone_fingerprint: 'abc123' },
       )
     end
 
@@ -43,6 +44,24 @@
 
         expect(Telephony::Test::Message.last_otp).to eq(otp)
       end
+
+      it 'logs a message being sent' do
+        expect(Telephony.config.logger).to receive(:info).with(
+          {
+            success: true,
+            errors: {},
+            request_id: 'fake-message-request-id',
+            message_id: 'fake-message-id',
+            phone_fingerprint: 'abc123',
+            adapter: :test,
+            channel: :sms,
+            context: :authentication,
+            country_code: 'US',
+          }.to_json,
+        )
+
+        subject.send_authentication_otp
+      end
     end
 
     context 'for Voice' do
@@ -71,6 +90,7 @@
         channel: channel,
         domain: domain,
         country_code: country_code,
+        extra_metadata: {},
       )
     end
 
@@ -199,6 +219,7 @@
         expiration: Time.zone.now,
         domain: 'login.gov',
         country_code: country_code,
+        extra_metadata: {},
       )
     end
 
@@ -252,6 +273,7 @@
         expiration: TwoFactorAuthenticatable::DIRECT_OTP_VALID_FOR_MINUTES,
         domain: 'secure.login.gov',
         country_code: 'US',
+        extra_metadata: {},
       )
     end
 
@@ -300,6 +322,7 @@
         expiration: TwoFactorAuthenticatable::DIRECT_OTP_VALID_FOR_MINUTES,
         domain: 'secure.login.gov',
         country_code: 'US',
+        extra_metadata: {},
       )
     end
 

spec/services/idv/send_phone_confirmation_otp_spec.rb

@@ -2,6 +2,7 @@
 
 describe Idv::SendPhoneConfirmationOtp do
   let(:phone) { '+1 225-555-5000' }
+  let(:parsed_phone) { Phonelib.parse(phone) }
   let(:delivery_preference) { :sms }
   let(:otp_code) { '777777' }
   let(:user_phone_confirmation_session) do
@@ -62,6 +63,11 @@
           channel: :sms,
           domain: IdentityConfig.store.domain_name,
           country_code: 'US',
+          extra_metadata: {
+            area_code: parsed_phone.area_code,
+            phone_fingerprint: Pii::Fingerprinter.fingerprint(parsed_phone.e164),
+            resend: nil,
+          },
         )
       end
     end
@@ -89,6 +95,11 @@
           channel: :voice,
           domain: IdentityConfig.store.domain_name,
           country_code: 'US',
+          extra_metadata: {
+            area_code: parsed_phone.area_code,
+            phone_fingerprint: Pii::Fingerprinter.fingerprint(parsed_phone.e164),
+            resend: nil,
+          },
         )
       end
     end