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

ReceiptFetcher: added retry mechanism #1945

Merged
merged 10 commits into from
Oct 7, 2022
Merged

ReceiptFetcher: added retry mechanism #1945

merged 10 commits into from
Oct 7, 2022

Conversation

NachoSoto
Copy link
Contributor

@NachoSoto NachoSoto commented Sep 27, 2022

Fixes CSDK-478

Depends on #1941, #1942, and #1943.

Example:

Log of a successful purchase after retrying 🎉

INFO: 💰 Purchasing Product 'com.revenuecat.monthly_4.99.1_week_intro'
DEBUG: ℹ️ Loaded receipt from url file:///Users/nachosoto/Library/Developer/CoreSimulator/Devices/A3576DC2-355E-45BA-B32C-D2C0A3811BB4/data/Containers/Data/Application/7ACD12DA-2A12-4CF1-8A76-8295E40B64EF/StoreKit/receipt
INFO: ℹ️ Receipt parsed successfully
WARN: 🍎‼️ Local receipt is still missing purchase for 'com.revenuecat.monthly_4.99.1_week_intro':
{
"opaque_value" : "79v2XwwAAAA=",
"sha1_hash" : "GhOmfuioo2Z4R3zX8K60l4b0qgs=",
"bundle_id" : "com.revenuecat.StoreKitTestApp",
"in_app_purchases" : [
{
"quantity" : 1,
"product_id" : "com.revenuecat.monthly_4.99.1_week_intro",
"purchase_date" : "2022-09-28T01:14:24Z",
"transaction_id" : "0",
"is_in_intro_offer_period" : true,
"expires_date" : "2022-09-28T01:14:34Z"
}
],
"application_version" : "1",
"creation_date" : "2022-09-28T01:14:24Z",
"expiration_date" : "4001-01-01T00:00:00Z"
}
DEBUG: ℹ️ Retrying Receipt fetch after 5 seconds
DEBUG: ℹ️ API request completed: POST /v1/receipts 200
DEBUG: ℹ️ PostReceiptDataOperation: Finished
DEBUG: ℹ️ Serial request done: POST receipts, 0 requests left in the queue
DEBUG: ℹ️ Sending updated CustomerInfo to delegate.
DEBUG: ℹ️ Found 0 unsynced attributes for App User ID: $RCAnonymousID:ec326c1613c14b489980eace90dceabb
DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
DEBUG: ℹ️ Loaded receipt from url file:///Users/nachosoto/Library/Developer/CoreSimulator/Devices/A3576DC2-355E-45BA-B32C-D2C0A3811BB4/data/Containers/Data/Application/7ACD12DA-2A12-4CF1-8A76-8295E40B64EF/StoreKit/receipt
DEBUG: ℹ️ PostReceiptDataOperation: Started
INFO: ℹ️ Receipt parsed successfully
DEBUG: ℹ️ PostReceiptDataOperation: Posting receipt: {
"opaque_value" : "0nf1uwEAAAA=",
"sha1_hash" : "lfxVVsBuSkQLtrGJseZ8zlpXc5A=",
"bundle_id" : "com.revenuecat.StoreKitTestApp",
"in_app_purchases" : [
{
"quantity" : 1,
"product_id" : "com.revenuecat.monthly_4.99.1_week_intro",
"purchase_date" : "2022-09-28T01:14:24Z",
"transaction_id" : "0",
"is_in_intro_offer_period" : true,
"expires_date" : "2022-09-28T01:14:34Z"
},
{
"product_id" : "com.revenuecat.monthly_4.99.1_week_intro",
"quantity" : 1,
"transaction_id" : "1",
"is_in_intro_offer_period" : false,
"expires_date" : "2022-09-28T01:15:04Z",
"original_purchase_date" : "2022-09-28T01:14:24Z",
"original_transaction_id" : "0",
"purchase_date" : "2022-09-28T01:14:34Z"
}
],
"application_version" : "1",
"creation_date" : "2022-09-28T01:14:35Z",
"expiration_date" : "4001-01-01T00:00:00Z"
}
DEBUG: ℹ️ There are no requests currently running, starting request POST receipts
DEBUG: ℹ️ API request started: POST /v1/receipts
DEBUG: ℹ️ API request completed: POST /v1/receipts 200
DEBUG: ℹ️ PostReceiptDataOperation: Finished
DEBUG: ℹ️ Serial request done: POST receipts, 0 requests left in the queue
DEBUG: ℹ️ Sending updated CustomerInfo to delegate.
DEBUG: ℹ️ Loaded receipt from url file:///Users/nachosoto/Library/Developer/CoreSimulator/Devices/A3576DC2-355E-45BA-B32C-D2C0A3811BB4/data/Containers/Data/Application/7ACD12DA-2A12-4CF1-8A76-8295E40B64EF/StoreKit/receipt
INFO: ℹ️ Receipt parsed successfully
DEBUG: ℹ️ Skipping products request because products were already cached. products: ["com.revenuecat.monthly_4.99.1_week_intro"]
DEBUG: ℹ️ Skipping products request because products were already cached. products: ["com.revenuecat.monthly_4.99.1_week_intro"]
DEBUG: ℹ️ Store products request finished
DEBUG: ℹ️ Found 0 unsynced attributes for App User ID: $RCAnonymousID:ec326c1613c14b489980eace90dceabb
DEBUG: ℹ️ PostReceiptDataOperation: Started
INFO: ℹ️ Receipt parsed successfully
DEBUG: ℹ️ PostReceiptDataOperation: Posting receipt: {
"opaque_value" : "tv4/2gcAAAA=",
"sha1_hash" : "0rh1naTc3JyfM16M/1f6fw4ezAY=",
"bundle_id" : "com.revenuecat.StoreKitTestApp",
"in_app_purchases" : [
{
"quantity" : 1,
"product_id" : "com.revenuecat.monthly_4.99.1_week_intro",
"purchase_date" : "2022-09-28T01:14:24Z",
"transaction_id" : "0",
"is_in_intro_offer_period" : true,
"expires_date" : "2022-09-28T01:14:34Z"
},
{
"product_id" : "com.revenuecat.monthly_4.99.1_week_intro",
"quantity" : 1,
"transaction_id" : "1",
"is_in_intro_offer_period" : false,
"expires_date" : "2022-09-28T01:15:04Z",
"original_purchase_date" : "2022-09-28T01:14:24Z",
"original_transaction_id" : "0",
"purchase_date" : "2022-09-28T01:14:34Z"
}
],
"application_version" : "1",
"creation_date" : "2022-09-28T01:14:40Z",
"expiration_date" : "4001-01-01T00:00:00Z"
}
DEBUG: ℹ️ There are no requests currently running, starting request POST receipts
DEBUG: ℹ️ API request started: POST /v1/receipts
DEBUG: ℹ️ API request completed: POST /v1/receipts 200
DEBUG: ℹ️ PostReceiptDataOperation: Finished
DEBUG: ℹ️ Serial request done: POST receipts, 0 requests left in the queue
INFO: 😻💰 Purchased product - 'com.revenuecat.monthly_4.99.1_week_intro'

@NachoSoto NachoSoto added the pr:fix A bug fix label Sep 27, 2022
@NachoSoto NachoSoto requested a review from a team September 27, 2022 21:19
@NachoSoto NachoSoto force-pushed the receipt-fetch-retries branch 6 times, most recently from e0eb66b to ba64e84 Compare September 28, 2022 00:48
@NachoSoto NachoSoto changed the title [WIP] ReceiptFetcher: added retry mechanism ReceiptFetcher: added retry mechanism Sep 28, 2022
@NachoSoto NachoSoto marked this pull request as ready for review September 28, 2022 00:48
@@ -740,6 +741,15 @@ private extension PurchasesOrchestrator {
}
}

private func refreshRequestPolicy(forProductIdentifier productIdentifier: String) -> ReceiptRefreshPolicy {
if self.systemInfo.isSandbox {
Copy link
Contributor Author

Choose a reason for hiding this comment

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

Enabled only in sandbox for now

Sources/Logging/Strings/ReceiptStrings.swift Outdated Show resolved Hide resolved
Sources/Logging/Strings/ReceiptStrings.swift Outdated Show resolved Hide resolved

var isActiveSubscription: Bool {
guard self.productType?.isSubscription == true else { return false }
guard let expiration = self.expiresDate else { return true }
Copy link
Contributor

Choose a reason for hiding this comment

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

When would this happen?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

A purchase without expiration?

Copy link
Member

Choose a reason for hiding this comment

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

non subscriptions won't have expiration dates

Copy link
Member

Choose a reason for hiding this comment

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

so in theory you'd never get here, but better safe than sorry


func containsActivePurchase(forProductIdentifier identifier: String) -> Bool {
return (self.inAppPurchases.contains { $0.isActiveSubscription } ||
self.inAppPurchases.contains { $0.productId == identifier })
Copy link
Contributor

Choose a reason for hiding this comment

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

Since you're doing ||... Wouldn't this statement return true if there's an active subscription for a product identifier? It would also return true if there's an inactive subscription for that productId.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Yeah, I think this is the logic we ended up agreeing on to avoid false negatives during a presubscription. @aboedo did I do this right?

Copy link
Member

Choose a reason for hiding this comment

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

ohhh I see what @vegaro means, though - if you made any purchases for a past subscription this will now be true.
it should be either of:

  • you have any active subscriptions at all (this is just in case of upgrades, where product id won't be the same as the one you purchased)
  • you have a non-subscription purchase for that product identifier
    But if you only have an expired subscription for that product identifier this should be false

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Okay I'll update this logic 👍🏻

Once that's finished, are we okay merging this PR enabled only for sandbox then? At the very least it will help integration tests. We could also only enable it for tests.

Copy link
Member

Choose a reason for hiding this comment

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

we can start by having it for tests only and figure out next steps once we have a clearer picture of how to tackle triage-82

Copy link
Contributor Author

Choose a reason for hiding this comment

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

That would be risk-free, since the only difference is a separate fetch policy that for now is unused :)

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Okay logic updated.

NachoSoto added a commit that referenced this pull request Sep 29, 2022
…xpires` to fix flakiness (#1952)

Fixes [CSDK-479].

### Changes:
- Removed extra `verifyEntitlementWentThrough`. #1880 introduced a
change so that weekly subscriptions aren't verified, because they expire
within a second. This make the test flaky due to that race condition.
- Removed `assertNoActiveSubscription`: I tried calling
`SKTestSession.disableAutoRenewForTransaction`, but sometimes the server
still thinks the subscription has auto-renewed. This was making the test
flaky. Turns out that even if it's not active, the eligibility test
still passes as expected.
- Removed call to `syncPurchases`. It doesn't matter what state the
server is in, as long as locally `SKTestSession` has an expired
subscription.

This, together with #1945, should fix the last of the issues causing
flaky integration tests 🤞🏻

[CSDK-479]:
https://revenuecats.atlassian.net/browse/CSDK-479?atlOrigin=eyJpIjoiNWRkNTljNzYxNjVmNDY3MDlhMDU5Y2ZhYzA5YTRkZjUiLCJwIjoiZ2l0aHViLWNvbS1KU1cifQ
@NachoSoto NachoSoto requested review from vegaro and a team September 30, 2022 17:48
@NachoSoto NachoSoto force-pushed the receipt-fetch-retries branch 2 times, most recently from cd63ddd to cc52ff1 Compare September 30, 2022 20:37
Purchases.logLevel = .debug
Purchases.shared.delegate = self.purchasesDelegate
}

private var dangerousSettings: DangerousSettings {
return .init(autoSyncPurchases: true,
internalSettings: .init(enableReceiptFetchRetry: true))
Copy link
Contributor Author

Choose a reason for hiding this comment

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

New DangerousSettings API to be able to set options without exposing them as public.

NachoSoto and others added 7 commits October 7, 2022 07:26
Co-authored-by: Cesar de la Vega <cesarvegaro@gmail.com>
Co-authored-by: Cesar de la Vega <cesarvegaro@gmail.com>
@NachoSoto NachoSoto merged commit c00be57 into main Oct 7, 2022
@NachoSoto NachoSoto deleted the receipt-fetch-retries branch October 7, 2022 14:55
NachoSoto added a commit that referenced this pull request Nov 4, 2022
…ons`

This changes the default back to `StoreKit 1`. We decided to do this for the following reasons:
- Purchasing with `PromotionalOffer`s does not work with StoreKit 2 due to an Apple bug (see #2020 (comment))
- `checkTrialOrIntroDiscountEligibility` is significantly slower with StoreKit 2 (#1893). We're adding optimizations to help with that (#2007), but the underlying logic will still be slow.
- A rare race-condition where `StoreKit 2` does not have transactions after a purchase ([TRIAGE-82]). We have some workarounds (#1945), but it's still being investigated.

_ Note: This effectively reverts 0ee540a. That commit made it easier to only change the default in one place which is why this PR is basically just one line._
NachoSoto added a commit that referenced this pull request Nov 4, 2022
… "invalid" receipt

See #1945.
To make this retry mechanism less risky when eventually enabled, this change makes the "worst case scenario" (where retrying didn't help, or `AppleReceipt.containsActivePurchase` has issues) equivalent to `ReceiptFetcher.onlyIfEmpty`.
NachoSoto added a commit that referenced this pull request Nov 4, 2022
…ons` (#2022)

This changes the default back to `StoreKit 1`. We decided to do this for
the following reasons:
- Purchasing with `PromotionalOffer`s does not work with StoreKit 2 due
to an Apple bug (see
#2020 (comment))
- `checkTrialOrIntroDiscountEligibility` is significantly slower with
`StoreKit 2` (#1893). We're adding optimizations to help with that
(#2007), but the underlying logic will still be slow.
- A rare race-condition where `StoreKit 2` does not have transactions
after a purchase ([TRIAGE-82]). We have some workarounds (#1945), but
it's still being investigated.

_Note: This effectively reverts 0ee540a. That commit made it easier to
only change the default in one place which is why this PR is basically
just one line._

[TRIAGE-82]:
https://revenuecats.atlassian.net/browse/TRIAGE-82?atlOrigin=eyJpIjoiNWRkNTljNzYxNjVmNDY3MDlhMDU5Y2ZhYzA5YTRkZjUiLCJwIjoiZ2l0aHViLWNvbS1KU1cifQ
NachoSoto added a commit that referenced this pull request Nov 9, 2022
… "invalid" receipt (#2024)

See #1945.

To make this retry mechanism less risky when eventually enabled, this
change makes the "worst case scenario" (where retrying didn't help, or
`AppleReceipt.containsActivePurchase` has issues) equivalent to
`ReceiptFetcher.onlyIfEmpty`.

_Note: this is currently not enabled in production, only in Integration Tests._
NachoSoto added a commit to RevenueCat/purchases-hybrid-common that referenced this pull request Dec 19, 2022
NachoSoto added a commit to RevenueCat/purchases-hybrid-common that referenced this pull request Dec 19, 2022
NachoSoto added a commit that referenced this pull request Feb 15, 2023
Fixes #2260 and [SDKONCALL-216].
Follow up to #2245.

The change in #2245 was meant to avoid receipt refresh throttling errors (#2116).
However, that was a regression when using StoreKit config files because those don't get refreshed in the backend.

Unfortunately the workaround introduced in #1945 prevented us from noticing this, because we use `DangerousSettings.InternalSettings.enableReceiptFetchRetry` in our own integration tests.
I added an integration test that explicitly covers this scenario. That fails without this change if disabling that dangerous setting. I thought about making that test run without the setting, but that might lead to flaky failures in CI, which is why we introduced that workaround in the first place. But at least now we have an explicit integration test for this, as well as 2 unit tests.
NachoSoto added a commit that referenced this pull request Feb 15, 2023
…2280)

Fixes #2260 and [SDKONCALL-216].
Follow up to #2245.

The change in #2245 was meant to avoid receipt refresh throttling errors
(#2116).
However, that was a regression when using StoreKit config files because
those don't get refreshed in the backend.

Unfortunately the workaround introduced in #1945 prevented us from
noticing this, because we use
`DangerousSettings.InternalSettings.enableReceiptFetchRetry` in our own
integration tests.
I added an integration test that explicitly covers this scenario. That
fails without this change if disabling that dangerous setting. I thought
about making that test run without the setting, but that might lead to
flaky failures in CI, which is why we introduced that workaround in the
first place. But at least now we have an explicit integration test for
this, as well as 2 unit tests.


[SDKONCALL-216]:
https://revenuecats.atlassian.net/browse/SDKONCALL-216?atlOrigin=eyJpIjoiNWRkNTljNzYxNjVmNDY3MDlhMDU5Y2ZhYzA5YTRkZjUiLCJwIjoiZ2l0aHViLWNvbS1KU1cifQ
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
pr:fix A bug fix
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants