Add logging for contact information updates (#12398)

* Add logging for contact information updates

* Add more logging locations and start tweaking tests

* Add expiration to test

* Move logging and tests to profile base controller

* Please rubocop

* Remove duplicate logging

* Remove duplicate logging

* Move files back

* Remove unnecessary file

* Make rubocop happy

modules/mobile/app/controllers/mobile/v0/profile_base_controller.rb

@@ -9,6 +9,8 @@ class ProfileBaseController < ApplicationController
       include Vet360::Writeable
 
       before_action { authorize :vet360, :access? }
+
+      after_action :log_sso_info, only: %i[create update destroy]
       after_action :invalidate_cache
 
       skip_after_action :invalidate_cache, only: [:validation]
@@ -22,6 +24,53 @@ def render_transaction_to_json(transaction)
       def service
         Mobile::V0::Profile::SyncUpdateService.new(@current_user)
       end
+
+      def log_sso_info
+        action = request.controller_instance.controller_path.classify.to_s
+        action += 'Controller#'
+        action += request.parameters['action'].to_s
+
+        Rails.logger.warn(
+          "#{action} request completed", sso_logging_info
+        )
+      end
+
+      def sso_logging_info
+        { user_uuid: @current_user&.uuid,
+          sso_cookie_contents: sso_cookie_content,
+          request_host: request.host }
+      end
+
+      def sso_cookie_content
+        return nil if @current_user.blank?
+
+        { 'patientIcn' => @current_user.icn,
+          'signIn' => @current_user.identity.sign_in.deep_transform_keys { |key| key.to_s.camelize(:lower) },
+          'credential_used' => @current_user.identity.sign_in[:service_name],
+          'expirationTime' => if sis_authentication?
+                                sign_in_expiration_time
+                              else
+                                @current_user.identity.expiration_timestamp
+                              end }
+      end
+
+      def sign_in_expiration_time
+        if sis_authentication?
+          if sign_in_service_session
+            sign_in_service_session.refresh_expiration.iso8601(0)
+          else
+            @session_object.ttl_in_time.iso8601(0)
+          end
+        else
+          @current_user.identity.expiration_timestamp
+        end
+      end
+
+      def sign_in_service_session
+        return unless @access_token
+
+        @sign_in_service_session ||= SignIn::OAuthSession.find_by(handle: @access_token.session_handle)
+      end
     end
   end
 end

modules/mobile/spec/controllers/profile_base_controller_spec.rb

@@ -0,0 +1,94 @@
+# frozen_string_literal: true
+
+require 'rails_helper'
+require_relative '../support/sis_session_helper'
+require_relative '../support/iam_session_helper'
+require_relative '../support/matchers/json_schema_matcher'
+
+RSpec.shared_examples 'sso logging' do |type|
+  describe "#{type} logging" do
+    before do
+      allow(Rails.logger).to receive(:warn)
+
+      if type == :sis
+        @new_headers = sis_headers
+      else
+        @new_headers = iam_headers
+        iam_sign_in
+      end
+    end
+
+    it 'logs after create' do
+      request.headers.merge! @new_headers
+      post :create
+
+      log_name = nil
+      log_value = nil
+
+      expect(Rails.logger).to have_received(:warn) do |name, value|
+        log_name = name
+        log_value = value.to_json
+      end
+
+      expect(log_name).to eq('Mobile::V0::ProfileBaseController#create request completed')
+      expect(log_value).to match_json_schema('sso_log')
+    end
+
+    it 'logs after update' do
+      request.headers.merge! @new_headers
+      put :update, params: {
+        id: 1
+      }
+
+      log_name = nil
+      log_value = nil
+
+      expect(Rails.logger).to have_received(:warn) do |name, value|
+        log_name = name
+        log_value = value.to_json
+      end
+
+      expect(log_name).to eq('Mobile::V0::ProfileBaseController#update request completed')
+      expect(log_value).to match_json_schema('sso_log')
+    end
+
+    it 'logs after destroy' do
+      request.headers.merge! @new_headers
+      delete :destroy, params: {
+        id: 1
+      }
+
+      log_name = nil
+      log_value = nil
+
+      expect(Rails.logger).to have_received(:warn) do |name, value|
+        log_name = name
+        log_value = value.to_json
+      end
+
+      expect(log_name).to eq('Mobile::V0::ProfileBaseController#destroy request completed')
+      expect(log_value).to match_json_schema('sso_log')
+    end
+  end
+end
+
+RSpec.describe Mobile::V0::ProfileBaseController, type: :controller do
+  include JsonSchemaMatchers
+
+  controller do
+    def create
+      head :ok
+    end
+
+    def update
+      head :ok
+    end
+
+    def destroy
+      head :ok
+    end
+  end
+
+  include_examples 'sso logging', :iam
+  include_examples 'sso logging', :sis
+end

modules/mobile/spec/support/schemas/sso_log.json

@@ -0,0 +1,52 @@
+{
+  "$schema": "http://json-schema.org/draft-04/schema#",
+  "type": "object",
+  "required": [
+    "user_uuid",
+    "sso_cookie_contents",
+    "request_host"
+  ],
+  "properties": {
+    "user_uuid": {
+      "type": "string"
+    },
+    "sso_cookie_contents": {
+      "type": "object",
+      "required": [
+        "patientIcn",
+        "signIn",
+        "credential_used",
+        "expirationTime"
+      ],
+      "properties": {
+        "patientIcn": {
+          "type": "string"
+        },
+        "signIn": {
+          "type": "object",
+          "required": [
+            "serviceName",
+            "authBroker"
+          ],
+          "properties": {
+            "serviceName": {
+              "type": "string"
+            },
+            "clientId": {
+              "type": "string"
+            },
+            "authBroker": {
+              "type": "string"
+            }
+          }
+        },
+        "credential_used": {
+          "type": "string"
+        }
+      }
+    },
+    "request_host": {
+      "type": "string"
+    }
+  }
+}

modules/mobile/spec/support/sis_session_helper.rb

@@ -0,0 +1,29 @@
+# frozen_string_literal: true
+
+module SISSessionHelper
+  def sis_access_token
+    @sis_access_token ||= create(:access_token)
+  end
+
+  def sis_bearer_token
+    @sis_bearer_token ||= SignIn::AccessTokenJwtEncoder.new(access_token: sis_access_token).perform
+  end
+
+  def sis_user
+    @sis_user ||= create(:user, :api_auth, uuid: sis_access_token.user_uuid)
+  end
+
+  def sis_headers(additional_headers = nil)
+    headers = {
+      'Authorization' => "Bearer #{sis_bearer_token}",
+      'X-Key-Inflection' => 'camel',
+      'Authentication-Method' => 'SIS'
+    }
+    headers.merge!(additional_headers) if additional_headers
+    headers
+  end
+end
+
+RSpec.configure do |config|
+  config.include SISSessionHelper
+end

spec/factories/iam_user_identities.rb

@@ -14,6 +14,7 @@
     icn { '1008596379V859838' }
     multifactor { true }
     iam_edipi { '1005079124' }
+    expiration_timestamp { 1.day.from_now.to_i.to_s }
 
     sign_in do
       {