Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Embedded GA metrics #4507

Merged
merged 16 commits into from
Jan 31, 2025
Merged
Show file tree
Hide file tree
Changes from 8 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,7 @@ class EmbeddedUITests: PaymentSheetUITestCase {
.filter({ !$0.starts(with: "luxe") })
XCTAssertEqual(
startupLog,
["mc_load_started", "link.account_lookup.complete", "mc_load_succeeded", "mc_embedded_init"]
["mc_load_started_embedded", "link.account_lookup.complete", "mc_load_succeeded_embedded", "mc_embedded_init"]
)

// Entering a card w/ deferred PaymentIntent...
Expand Down Expand Up @@ -73,7 +73,7 @@ class EmbeddedUITests: PaymentSheetUITestCase {
let aliPayAnalytics = analyticsLog.compactMap({ $0[string: "event"] })
XCTAssertEqual(
aliPayAnalytics,
["mc_load_started", "link.account_lookup.complete", "mc_load_succeeded", "mc_carousel_payment_method_tapped"]
["mc_embedded_update_started", "mc_load_started_embedded", "link.account_lookup.complete", "mc_load_succeeded_embedded", "mc_embedded_update_finished", "mc_carousel_payment_method_tapped"]
)

// ...and *updating* to a SetupIntent...
Expand Down Expand Up @@ -122,9 +122,7 @@ class EmbeddedUITests: PaymentSheetUITestCase {
let klarnaAnalytics = analyticsLog.compactMap({ $0[string: "event"] })
XCTAssertEqual(
klarnaAnalytics,
["mc_load_started", "link.account_lookup.complete", "mc_load_succeeded", "mc_carousel_payment_method_tapped",
"mc_form_shown", "mc_form_completed", "mc_confirm_button_tapped",
]
["mc_embedded_update_started", "mc_load_started_embedded", "link.account_lookup.complete", "mc_load_succeeded_embedded", "mc_embedded_update_finished", "mc_carousel_payment_method_tapped", "mc_form_shown", "mc_form_completed", "mc_confirm_button_tapped"]
)

// ...switching back to payment should keep Klarna selected
Expand Down Expand Up @@ -250,7 +248,7 @@ class EmbeddedUITests: PaymentSheetUITestCase {
.prefix(5)
XCTAssertEqual(
presentEmbeddedLog,
["mc_load_started", "mc_load_succeeded", "mc_embedded_init", "mc_carousel_payment_method_tapped", "mc_form_shown"]
["mc_load_started_embedded", "mc_load_succeeded_embedded", "mc_embedded_init", "mc_carousel_payment_method_tapped", "mc_form_shown"]
)

// Complete payment
Expand Down Expand Up @@ -518,7 +516,7 @@ class EmbeddedUITests: PaymentSheetUITestCase {

let loadEventsWithoutSPMSelection = analyticsLog.compactMap({ $0[string: "event"] })
.filter({ $0.starts(with: "mc_") }).prefix(3)
XCTAssertEqual(loadEventsWithoutSPMSelection, ["mc_load_started", "mc_load_succeeded", "mc_embedded_init"])
XCTAssertEqual(loadEventsWithoutSPMSelection, ["mc_load_started_embedded", "mc_load_succeeded_embedded", "mc_embedded_init"])

let confirmationEvents = analyticsLog.compactMap({ $0[string: "event"] })
.filter({ $0.starts(with: "mc_") }).suffix(1)
Expand Down
16 changes: 15 additions & 1 deletion StripeCore/StripeCore/Source/Analytics/STPAnalyticEvent.swift
Original file line number Diff line number Diff line change
Expand Up @@ -77,7 +77,21 @@ import Foundation

// MARK: - Embedded Payment Element init
case mcInitEmbedded = "mc_embedded_init"


// MARK: - Embedded Payment Element loading
case mcLoadStartedEmbedded = "mc_load_started_embedded"
case mcLoadSucceededEmbedded = "mc_load_succeeded_embedded"
case mcLoadFailedEmbedded = "mc_load_failed_embedded"
porter-stripe marked this conversation as resolved.
Show resolved Hide resolved

// MARK: - Embedded Payment Element confirm
case mcConfirmEmbedded = "mc_embedded_confirm"

// MARK: - Embedded Payment Element update
case mcUpdateStartedEmbedded = "mc_embedded_update_started"
case mcUpdateFinishedEmbedded = "mc_embedded_update_finished"
case mcUpdateFailedEmbedded = "mc_embedded_update_failed"
case mcUpdateCanceledEmbedded = "mc_embedded_update_canceled"
porter-stripe marked this conversation as resolved.
Show resolved Hide resolved

// MARK: - PaymentSheet Show
case mcShowCustomNewPM = "mc_custom_sheet_newpm_show"
case mcShowCustomSavedPM = "mc_custom_sheet_savedpm_show"
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ final class PaymentSheetAnalyticsHelper {
var elementsSession: STPElementsSession?
var loadingStartDate: Date?
private var startTimes: [TimeMeasurement: Date] = [:]
private var updateStartDate: Date?

enum IntegrationShape {
case flowController
Expand Down Expand Up @@ -70,7 +71,15 @@ final class PaymentSheetAnalyticsHelper {

func logLoadStarted() {
loadingStartDate = Date()
log(event: .paymentSheetLoadStarted)
let event: STPAnalyticEvent = {
switch integrationShape {
case .complete, .flowController:
return .paymentSheetLoadStarted
case .embedded:
return .mcLoadStartedEmbedded
}
}()
log(event: event)
}

func logLoadFailed(error: Error) {
Expand All @@ -79,8 +88,16 @@ final class PaymentSheetAnalyticsHelper {
guard let loadingStartDate else { return 0 }
return Date().timeIntervalSince(loadingStartDate)
}()
let event: STPAnalyticEvent = {
switch integrationShape {
case .complete, .flowController:
return .paymentSheetLoadFailed
case .embedded:
return .mcLoadFailedEmbedded
}
}()
log(
event: .paymentSheetLoadFailed,
event: event,
duration: duration,
error: error
)
Expand Down Expand Up @@ -124,8 +141,16 @@ final class PaymentSheetAnalyticsHelper {
guard let loadingStartDate else { return 0 }
return Date().timeIntervalSince(loadingStartDate)
}()
let event: STPAnalyticEvent = {
switch integrationShape {
case .complete, .flowController:
return .paymentSheetLoadSucceeded
case .embedded:
return .mcLoadSucceededEmbedded
}
}()
log(
event: .paymentSheetLoadSucceeded,
event: event,
duration: duration,
params: params
)
Expand Down Expand Up @@ -320,6 +345,38 @@ final class PaymentSheetAnalyticsHelper {
linkUI: paymentOption.linkUIAnalyticsValue
)
}

func logEmbeddedUpdateStarted() {
stpAssert(integrationShape == .embedded, "This function should only be used with embedded integration")
updateStartDate = Date()
log(event: .mcUpdateStartedEmbedded)
}

func logEmbeddedUpdateFinished(result: EmbeddedPaymentElement.UpdateResult) {
stpAssert(integrationShape == .embedded, "This function should only be used with embedded integration")
let duration: TimeInterval? = {
guard let updateStartDate else { return nil }
return Date().timeIntervalSince(updateStartDate)
}()

let event: STPAnalyticEvent = {
switch result {
case .succeeded:
return .mcUpdateFinishedEmbedded
case .failed:
return .mcUpdateFailedEmbedded
case .canceled:
return .mcUpdateCanceledEmbedded
}
}()

var params: [String: Any] = [:]
if case .failed(let error) = result {
params["error"] = error.localizedDescription
}

log(event: event, duration: duration, params: params)
}

func log(
event: STPAnalyticEvent,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -115,6 +115,12 @@ public final class EmbeddedPaymentElement {
_ = await latestUpdateTask?.value
// Start the new update task
let currentUpdateTask = Task { @MainActor [weak self, configuration, analyticsHelper] in
analyticsHelper.logEmbeddedUpdateStarted()
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why log here and not at the start of the update method?

Copy link
Collaborator Author

@porter-stripe porter-stripe Jan 30, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good question! I think we should log when the update work actually begins not when it is scheduled. If we log it when it is scheduled (at the top of the function) it makes it harder to reason about the duration metric, since some will account for awaiting the previous update canceling and some won't. If we want consistency of the duration metric across all update events we should only measure the time the actual work associated with the update took, not accounting for any time it spent waiting for a previous update to cancel.

It's also convenient from an implementation standpoint with how we currently handle dates in the analytics helper. If we allow multiple update start events to be fired before the finished event it will overwrite the updateStartDate before the previous finished event could send.

If we fire the start event at the top we could get this
mc_embedded_update_started -> set's updateStartDate to x
mc_embedded_update_started -> set's updateStartDate to y
mc_embedded_update_finished -> reads updateStartDate set to y
mc_embedded_update_finished -> reads updateStartDate set to y

We could get around this by mapping update events and their start dates to a UUID so we know what start date to compute the duration on for all the finished events. But, putting the analytics in the Task ensures the ordering is correct/consistent which I prefer.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If we moved this to the start of update, duration represents the time it takes for the update method to finish. That feels quite simple and straightforward.

The total time the app spends waiting for update to finish also seems like a more useful duration metric. Like, why ignore the time spent waiting for previous update calls to finish? That's still time the app spends waiting and something we control (e.g. we could try to cancel in-flight tasks more aggressively).

Moving to the top has the additional benefit of capturing all possible errors.

Re: implementation - what if we keep track of the start time within the update method?

var updateResult: UpdateResult = .canceled // Default to canceled if unhandled
defer {
analyticsHelper.logEmbeddedUpdateFinished(result: updateResult)
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hm can we not log the result immediately before this method returns?

Copy link
Collaborator Author

@porter-stripe porter-stripe Jan 30, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Correct me if I'm wrong, but I believe there is a race condition. By the time you reach logEmbeddedUpdateFinished(result:) at the end of the function, a second update could have already started its own update and logged a start event. There’s no guarantee about which event comes first unless you serialize the calls within the same Task. Logging right before the method returns can record an “update finished” event out of order, or with an incorrect start date, if another update began in between.

latestUpdateTask?.cancel()
_ = await latestUpdateTask?.value
// Define task

let updateResult = await currentUpdateTask.value
analyticsHelper.logEmbeddedUpdateFinished(result: updateResult)
// After we await the update task we cannot guarantee this code runs before the next update task starts and logs an update started event, resetting the updateStartDate.

As I write this out, maybe we should just map update calls to a UUID and a start date to avoid this, but logging all the update events within the Task seems the safest with the current way we handle dates in the analytics helper. Even with that approach, we could get two update start events sent before an update finishes event, putting all the analytics in the Task ensures the order is correct/deterministic and makes it easier to reason about the ordering of the events, so I slightly prefer putting them within the Task.

Copy link
Collaborator

@yuki-stripe yuki-stripe Jan 30, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Imagine the merchant does the following

  1. Call update
  2. Call update again before (1) finishes.
  3. Receive Update (1) result
  4. Receive Update (2) result

I think you're saying the correct analytics ordering is:

  1. update_started
  2. update_finished
  3. update_started
  4. update_finished

That matches the ordering of the Tasks inside the update method.

I'm proposing (along with my other comment above) to model this analytic around the entire update method, not just the inner Task. This would make the ordering match the merchant's POV:

  1. update_started
  2. update_started
  3. update_finished
  4. update_finished

The ordering is still deterministic; update_started fires when the update API is called and update_finished fires when it returns.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sure we can do that 👍

}

// ⚠️ Don't modify `self` until the end to avoid being canceled halfway through and leaving self in a partially updated state.
// 1. Reload v1/elements/session.
let loadResult: PaymentSheetLoader.LoadResult
Expand All @@ -127,10 +133,12 @@ public final class EmbeddedPaymentElement {
integrationShape: .embedded
)
} catch {
return UpdateResult.failed(error: error)
updateResult = UpdateResult.failed(error: error)
return updateResult
}
guard !Task.isCancelled else {
return UpdateResult.canceled
updateResult = UpdateResult.canceled
return updateResult
}

// Store the old payment option before we update self.formViewController
Expand Down Expand Up @@ -167,7 +175,8 @@ public final class EmbeddedPaymentElement {
_ = await fetchPaymentOption.value

guard let self, !Task.isCancelled else {
return .canceled
updateResult = UpdateResult.canceled
return updateResult
}
// At this point, we're still the latest update and update is successful - update self properties and inform our delegate.
self.savedPaymentMethods = loadResult.savedPaymentMethods
Expand All @@ -179,7 +188,8 @@ public final class EmbeddedPaymentElement {
if oldPaymentOption != self.paymentOption {
self.delegate?.embeddedPaymentElementDidUpdatePaymentOption(embeddedPaymentElement: self)
}
return .succeeded
updateResult = .succeeded
return updateResult
}
self.latestUpdateTask = currentUpdateTask
let updateResult = await currentUpdateTask.value
Expand All @@ -202,6 +212,7 @@ public final class EmbeddedPaymentElement {
stpAssertionFailure(errorMessage)
return .failed(error: PaymentSheetError.integrationError(nonPIIDebugDescription: errorMessage))
}
analyticsHelper.log(event: .mcConfirmEmbedded)
porter-stripe marked this conversation as resolved.
Show resolved Hide resolved
let authContext = STPAuthenticationContextWrapper(presentingViewController: presentingViewController)
return await _confirm(paymentOption: paymentOption, authContext: authContext).result
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -93,8 +93,8 @@ class EmbeddedPaymentElementTest: XCTestCase {

// Sanity check that the analytics...
let analytics = STPAnalyticsClient.sharedClient._testLogHistory
let loadStartedEvents = analytics.filter { $0["event"] as? String == "mc_load_started" }
let loadSucceededEvents = analytics.filter { $0["event"] as? String == "mc_load_succeeded" }
let loadStartedEvents = analytics.filter { $0["event"] as? String == "mc_load_started_embedded" }
let loadSucceededEvents = analytics.filter { $0["event"] as? String == "mc_load_succeeded_embedded" }
// ...have the expected # of start and succeeded events...
XCTAssertEqual(loadStartedEvents.count, 3)
XCTAssertEqual(loadSucceededEvents.count, 3)
Expand Down Expand Up @@ -257,6 +257,12 @@ class EmbeddedPaymentElementTest: XCTestCase {
case .canceled:
XCTFail("Expected confirm to succeed, but it was canceled")
}

// Check our confirm analytics
let analytics = STPAnalyticsClient.sharedClient._testLogHistory
let confirmEvents = analytics.filter { $0["event"] as? String == "mc_embedded_confirm" }
// ...have the expected # of confirm events...
XCTAssertEqual(confirmEvents.count, 1)
}

func testConfirmWithInvalidCard() async throws {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -140,6 +140,36 @@ final class PaymentSheetAnalyticsHelperTest: XCTestCase {
XCTAssertEqual(loadSucceededPayload["intent_type"] as? String, "payment_intent")
XCTAssertEqual(loadSucceededPayload["ordered_lpms"] as? String, "card,external_paypal")
}

func testLogLoadFailed_embedded() {
let sut = PaymentSheetAnalyticsHelper(integrationShape: .embedded, configuration: PaymentSheet.Configuration(), analyticsClient: analyticsClient)
// Load started -> failed
sut.logLoadStarted()
sut.logLoadFailed(error: NSError(domain: "domain", code: 1))
XCTAssertEqual(analyticsClient._testLogHistory[0]["event"] as? String, "mc_load_started_embedded")
XCTAssertEqual(analyticsClient._testLogHistory[1]["event"] as? String, "mc_load_failed_embedded")
XCTAssertLessThan(analyticsClient._testLogHistory[1]["duration"] as! Double, 1.0)
}

func testLogLoadSucceeded_embedded() {
let sut = PaymentSheetAnalyticsHelper(integrationShape: .embedded, configuration: PaymentSheet.Configuration(), analyticsClient: analyticsClient)
// Load started -> succeeded
sut.logLoadStarted()
sut.logLoadSucceeded(
intent: ._testValue(),
elementsSession: ._testCardValue(),
defaultPaymentMethod: .applePay,
orderedPaymentMethodTypes: [.stripe(.card), .external(._testPayPalValue())]
)
XCTAssertEqual(analyticsClient._testLogHistory[0]["event"] as? String, "mc_load_started_embedded")

let loadSucceededPayload = analyticsClient._testLogHistory[1]
XCTAssertEqual(loadSucceededPayload["event"] as? String, "mc_load_succeeded_embedded")
XCTAssertLessThan(loadSucceededPayload["duration"] as! Double, 1.0)
XCTAssertEqual(loadSucceededPayload["selected_lpm"] as? String, "apple_pay")
XCTAssertEqual(loadSucceededPayload["intent_type"] as? String, "payment_intent")
XCTAssertEqual(loadSucceededPayload["ordered_lpms"] as? String, "card,external_paypal")
}

func testLogShow() {
let paymentSheetHelper = PaymentSheetAnalyticsHelper(integrationShape: .complete, configuration: PaymentSheet.Configuration(), analyticsClient: analyticsClient)
Expand Down Expand Up @@ -369,6 +399,33 @@ final class PaymentSheetAnalyticsHelperTest: XCTestCase {
)
XCTAssertEqual(analyticsClient._testLogHistory.last!["link_context"] as? String, "link_card_brand")
}

func testLogEmbeddedUpdate() {
let sut = PaymentSheetAnalyticsHelper(integrationShape: .embedded, configuration: PaymentSheet.Configuration(), analyticsClient: analyticsClient)

// Test update started
sut.logEmbeddedUpdateStarted()
XCTAssertEqual(analyticsClient._testLogHistory.last!["event"] as? String, "mc_embedded_update_started")

// Test successful update
sut.logEmbeddedUpdateFinished(result: .succeeded)
XCTAssertEqual(analyticsClient._testLogHistory.last!["event"] as? String, "mc_embedded_update_finished")
XCTAssertNotNil(analyticsClient._testLogHistory.last!["duration"])

// Test failed update
sut.logEmbeddedUpdateStarted()
let error = NSError(domain: "test", code: 123, userInfo: [NSLocalizedDescriptionKey: "Test error"])
sut.logEmbeddedUpdateFinished(result: .failed(error: error))
XCTAssertEqual(analyticsClient._testLogHistory.last!["event"] as? String, "mc_embedded_update_failed")
XCTAssertNotNil(analyticsClient._testLogHistory.last!["duration"])
XCTAssertEqual(analyticsClient._testLogHistory.last!["error"] as? String, "Test error")

// Test canceled update
sut.logEmbeddedUpdateStarted()
sut.logEmbeddedUpdateFinished(result: .canceled)
XCTAssertEqual(analyticsClient._testLogHistory.last!["event"] as? String, "mc_embedded_update_canceled")
XCTAssertNotNil(analyticsClient._testLogHistory.last!["duration"])
}

// MARK: - Helpers

Expand Down
Loading