From 524983b158047951e3a570318ecae56c1bceabc3 Mon Sep 17 00:00:00 2001 From: Jonathan Hooper Date: Fri, 30 Aug 2024 14:25:23 -0400 Subject: [PATCH] LG-14253 Track time to complete proofing workflow (#11179) We want to start tracking how long it takes people to complete identity proofing. Part of that is understanding how long it takes people to go from the start of the process to the enter password step where their profile is created. At this point we want to know: 1. How long did it take the person to complete the workflow 2. What steps remain before person finishes proofing (i.e. verify-by-mail, in-person-proofing, or fraud review) The enter password submit events already logs enough information to determine the second. This commit starts tracking the duration of the proofing session by adding a timestamp at the welcome step and logging the elapsed seconds since on the enter password events. --- .../idv/enter_password_controller.rb | 2 ++ app/controllers/idv/welcome_controller.rb | 1 + app/services/analytics_events.rb | 6 ++++++ app/services/idv/session.rb | 5 +++++ .../idv/enter_password_controller_spec.rb | 4 +++- .../idv/welcome_controller_spec.rb | 17 +++++++++++++++- spec/features/idv/analytics_spec.rb | 20 +++++++++---------- 7 files changed, 43 insertions(+), 12 deletions(-) diff --git a/app/controllers/idv/enter_password_controller.rb b/app/controllers/idv/enter_password_controller.rb index 2ca053235a1..12881a61a5c 100644 --- a/app/controllers/idv/enter_password_controller.rb +++ b/app/controllers/idv/enter_password_controller.rb @@ -51,6 +51,7 @@ def create gpo_verification_pending: idv_session.profile.gpo_verification_pending?, in_person_verification_pending: idv_session.profile.in_person_verification_pending?, deactivation_reason: idv_session.profile.deactivation_reason, + proofing_workflow_time_in_seconds: idv_session.proofing_workflow_time_in_seconds, **ab_test_analytics_buckets, ) Funnel::DocAuth::RegisterStep.new(current_user.id, current_sp&.issuer). @@ -62,6 +63,7 @@ def create gpo_verification_pending: idv_session.profile.gpo_verification_pending?, in_person_verification_pending: idv_session.profile.in_person_verification_pending?, deactivation_reason: idv_session.profile.deactivation_reason, + proofing_workflow_time_in_seconds: idv_session.proofing_workflow_time_in_seconds, **ab_test_analytics_buckets, ) diff --git a/app/controllers/idv/welcome_controller.rb b/app/controllers/idv/welcome_controller.rb index c2928c47884..1008336ded2 100644 --- a/app/controllers/idv/welcome_controller.rb +++ b/app/controllers/idv/welcome_controller.rb @@ -9,6 +9,7 @@ class WelcomeController < ApplicationController before_action :confirm_not_rate_limited def show + idv_session.proofing_started_at ||= Time.zone.now.iso8601 analytics.idv_doc_auth_welcome_visited(**analytics_arguments) Funnel::DocAuth::RegisterStep.new(current_user.id, sp_session[:issuer]). diff --git a/app/services/analytics_events.rb b/app/services/analytics_events.rb index fe682f678fe..f8b0083bd84 100644 --- a/app/services/analytics_events.rb +++ b/app/services/analytics_events.rb @@ -1861,6 +1861,7 @@ def idv_doc_auth_welcome_visited(step:, analytics_id:, skip_hybrid_handoff: nil, # @param [String, nil] deactivation_reason Reason user's profile was deactivated, if any. # @param [String,nil] active_profile_idv_level ID verification level of user's active profile. # @param [String,nil] pending_profile_idv_level ID verification level of user's pending profile. + # @param [Integer,nil] proofing_workflow_time_in_seconds The time since starting proofing # @identity.idp.previous_event_name IdV: review info visited def idv_enter_password_submitted( success:, @@ -1874,6 +1875,7 @@ def idv_enter_password_submitted( proofing_components: nil, active_profile_idv_level: nil, pending_profile_idv_level: nil, + proofing_workflow_time_in_seconds: nil, **extra ) track_event( @@ -1889,6 +1891,7 @@ def idv_enter_password_submitted( proofing_components:, active_profile_idv_level:, pending_profile_idv_level:, + proofing_workflow_time_in_seconds:, **extra, ) end @@ -1949,6 +1952,7 @@ def idv_enter_password_visited( # @param [String,nil] active_profile_idv_level ID verification level of user's active profile. # @param [String,nil] pending_profile_idv_level ID verification level of user's pending profile. # @param [Array,nil] profile_history Array of user's profiles (oldest to newest). + # @param [Integer,nil] proofing_workflow_time_in_seconds The time since starting proofing # @see Reporting::IdentityVerificationReport#query This event is used by the identity verification # report. Changes here should be reflected there. # Tracks the last step of IDV, indicates the user successfully proofed @@ -1965,6 +1969,7 @@ def idv_final( active_profile_idv_level: nil, pending_profile_idv_level: nil, profile_history: nil, + proofing_workflow_time_in_seconds: nil, **extra ) track_event( @@ -1981,6 +1986,7 @@ def idv_final( active_profile_idv_level:, pending_profile_idv_level:, profile_history:, + proofing_workflow_time_in_seconds:, **extra, ) end diff --git a/app/services/idv/session.rb b/app/services/idv/session.rb index 9e76d23f2d6..e1c12d0e067 100644 --- a/app/services/idv/session.rb +++ b/app/services/idv/session.rb @@ -22,6 +22,7 @@ class Session phone_for_mobile_flow previous_phone_step_params profile_id + proofing_started_at redo_document_capture resolution_successful selfie_check_performed @@ -205,6 +206,10 @@ def add_failed_phone_step_number(phone) failed_phone_step_numbers << phone_e164 if !failed_phone_step_numbers.include?(phone_e164) end + def proofing_workflow_time_in_seconds + Time.zone.now - Time.zone.parse(proofing_started_at) if proofing_started_at.present? + end + def pii_from_user_in_flow_session user_session.dig('idv/in_person', :pii_from_user) end diff --git a/spec/controllers/idv/enter_password_controller_spec.rb b/spec/controllers/idv/enter_password_controller_spec.rb index e4cf07dc023..a8e760ce11e 100644 --- a/spec/controllers/idv/enter_password_controller_spec.rb +++ b/spec/controllers/idv/enter_password_controller_spec.rb @@ -27,6 +27,7 @@ allow(IdentityConfig.store).to receive(:usps_mock_fallback).and_return(false) allow(subject).to receive(:ab_test_analytics_buckets).and_return(ab_test_args) subject.idv_session.welcome_visited = true + subject.idv_session.proofing_started_at = 5.minutes.ago.iso8601 subject.idv_session.idv_consent_given = true subject.idv_session.flow_path = 'standard' subject.idv_session.pii_from_doc = Pii::StateId.new(**Idp::Constants::MOCK_IDV_APPLICANT) @@ -283,7 +284,7 @@ def show end end - it 'redirects to personal key path' do + it 'redirects to personal key path', :freeze_time do put :create, params: { user: { password: ControllerHelper::VALID_PASSWORD } } expect(@analytics).to have_logged_event( @@ -294,6 +295,7 @@ def show fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: false, + proofing_workflow_time_in_seconds: 5.minutes.to_i, **ab_test_args, ), ) diff --git a/spec/controllers/idv/welcome_controller_spec.rb b/spec/controllers/idv/welcome_controller_spec.rb index bd32fefbc61..269632a3177 100644 --- a/spec/controllers/idv/welcome_controller_spec.rb +++ b/spec/controllers/idv/welcome_controller_spec.rb @@ -64,15 +64,30 @@ ) end + it 'sets the proofing started timestamp', :freeze_time do + get :show + + expect(subject.idv_session.proofing_started_at).to eq(Time.zone.now.iso8601) + end + context 'welcome already visited' do - it 'does not redirect to agreement' do + before do subject.idv_session.welcome_visited = true + subject.idv_session.proofing_started_at = 5.minutes.ago.iso8601 + end + it 'does not redirect to agreement' do get :show expect(response).to render_template('idv/welcome/show') end + it 'does not overwrite the proofing started timestamp' do + get :show + + expect(subject.idv_session.proofing_started_at).to eq(5.minutes.ago.iso8601) + end + context 'and verify info already completed' do before do subject.idv_session.flow_path = 'standard' diff --git a/spec/features/idv/analytics_spec.rb b/spec/features/idv/analytics_spec.rb index 2e722d7f654..34f7fa02d53 100644 --- a/spec/features/idv/analytics_spec.rb +++ b/spec/features/idv/analytics_spec.rb @@ -226,12 +226,12 @@ proofing_components: lexis_nexis_address_proofing_components, }, :idv_enter_password_submitted => { - success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: false, + success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: false, proofing_workflow_time_in_seconds: 0.0, active_profile_idv_level: 'legacy_unsupervised', proofing_components: lexis_nexis_address_proofing_components }, 'IdV: final resolution' => { - success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: false, + success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: false, proofing_workflow_time_in_seconds: 0.0, active_profile_idv_level: 'legacy_unsupervised', profile_history: match_array(kind_of(Idv::ProfileLogging)), proofing_components: lexis_nexis_address_proofing_components @@ -341,12 +341,12 @@ proofing_components: lexis_nexis_address_proofing_components, }, :idv_enter_password_submitted => { - success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: false, + success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: false, proofing_workflow_time_in_seconds: 0.0, active_profile_idv_level: 'legacy_unsupervised', proofing_components: lexis_nexis_address_proofing_components }, 'IdV: final resolution' => { - success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: false, + success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: false, proofing_workflow_time_in_seconds: 0.0, active_profile_idv_level: 'legacy_unsupervised', profile_history: match_array(kind_of(Idv::ProfileLogging)), proofing_components: lexis_nexis_address_proofing_components @@ -442,11 +442,11 @@ proofing_components: gpo_letter_proofing_components }, :idv_enter_password_submitted => { - success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: true, in_person_verification_pending: false, + success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: true, in_person_verification_pending: false, proofing_workflow_time_in_seconds: 0.0, proofing_components: gpo_letter_proofing_components }, 'IdV: final resolution' => { - success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: true, in_person_verification_pending: false, + success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: true, in_person_verification_pending: false, proofing_workflow_time_in_seconds: 0.0, # NOTE: pending_profile_idv_level should be set here, a nil value is cached for current_user.pending_profile. profile_history: match_array(kind_of(Idv::ProfileLogging)), proofing_components: gpo_letter_proofing_components @@ -558,11 +558,11 @@ proofing_components: { document_check: 'usps', source_check: 'aamva', resolution_check: 'lexis_nexis', threatmetrix: threatmetrix, threatmetrix_review_status: 'pass', address_check: 'lexis_nexis_address' }, }, :idv_enter_password_submitted => { - success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: true, + success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: true, proofing_workflow_time_in_seconds: 0.0, proofing_components: { document_check: 'usps', source_check: 'aamva', resolution_check: 'lexis_nexis', threatmetrix: threatmetrix, threatmetrix_review_status: 'pass', address_check: 'lexis_nexis_address' } }, 'IdV: final resolution' => { - success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: true, + success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: true, proofing_workflow_time_in_seconds: 0.0, # NOTE: pending_profile_idv_level should be set here, a nil value is cached for current_user.pending_profile. profile_history: match_array(kind_of(Idv::ProfileLogging)), proofing_components: { document_check: 'usps', source_check: 'aamva', resolution_check: 'lexis_nexis', threatmetrix: threatmetrix, threatmetrix_review_status: 'pass', address_check: 'lexis_nexis_address' } @@ -680,12 +680,12 @@ proofing_components: lexis_nexis_address_proofing_components, }, :idv_enter_password_submitted => { - success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: false, + success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: false, proofing_workflow_time_in_seconds: 0.0, active_profile_idv_level: 'unsupervised_with_selfie', proofing_components: lexis_nexis_address_proofing_components }, 'IdV: final resolution' => { - success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: false, + success: true, fraud_review_pending: false, fraud_rejection: false, gpo_verification_pending: false, in_person_verification_pending: false, proofing_workflow_time_in_seconds: 0.0, active_profile_idv_level: 'unsupervised_with_selfie', profile_history: match_array(kind_of(Idv::ProfileLogging)), proofing_components: lexis_nexis_address_proofing_components