PurchasesOrchestrator: disambiguate transactions from the queue#2890
Conversation
There was a problem hiding this comment.
Logging this for awareness next time we have to debug these logs.
There was a problem hiding this comment.
I added this for awareness, but we'll eventually need to deal with this and remove this log.
The docs make this clear:
The contents of this property are undefined except when
transactionStateis set toSKPaymentTransactionState.purchasedorSKPaymentTransactionState.restored.
There was a problem hiding this comment.
This helps debug these failures.
63253e5 to
71ba0da
Compare
| self.logger.clearMessages() | ||
|
|
||
| // 6. Purchase again | ||
| _ = try await self.purchases.purchase(package: self.monthlyPackage) |
There was a problem hiding this comment.
❗ One thing I don't understand even after looking at the receipt posted: this call to purchase returns an inactive entitlement ❓
We should look into it either in this PR or in a separate test.
There was a problem hiding this comment.
I'll wait to talk to @aboedo about this cause I'm really confused.
There was a problem hiding this comment.
yeah, that's unexpected - that's what this whole PR is meant to address.
well, actually...
I mean, purchase is going to return right after seeing one of the queue values return. like, this case is still true:
The problem isn't just that the initiation_source was marked incorrectly, it's that we're returning that value for the purchase, when in reality we should ignore transactions that don't have that date entirely.
I'll comment in the corresponding line
f1e9ecb to
cc0f2f2
Compare
aboedo
left a comment
There was a problem hiding this comment.
Left a few comments. Looking great! But we need to think about the case where we're calling completion too early. Maybe we can pair up on this tomorrow?
| case (true, true): return .restore | ||
| case (false, _): return .queue | ||
| case (.some, true): return .restore |
There was a problem hiding this comment.
kinda feels like we're losing a little bit of readability in the transition from true -> some
There was a problem hiding this comment.
That's the only way to both check for it being nil and extract the value from it though. Any suggestion?
| callbacks[productIdentifier] = completion | ||
| callbacks[productIdentifier] = (completion, Date()) |
There was a problem hiding this comment.
wonder if we'll want to end up passing a date provider for this for tests
| self.logger.clearMessages() | ||
|
|
||
| // 6. Purchase again | ||
| _ = try await self.purchases.purchase(package: self.monthlyPackage) |
There was a problem hiding this comment.
yeah, that's unexpected - that's what this whole PR is meant to address.
well, actually...
I mean, purchase is going to return right after seeing one of the queue values return. like, this case is still true:
The problem isn't just that the initiation_source was marked incorrectly, it's that we're returning that value for the purchase, when in reality we should ignore transactions that don't have that date entirely.
I'll comment in the corresponding line
f7306ee to
24e53a3
Compare
| // This matches the behavior of `SKPaymentTransaction`. | ||
| guard self.transactionState == .purchased || self.transactionState == .restored else { | ||
| return nil | ||
| } |
There was a problem hiding this comment.
I'm glad I did this because this exposed how this is breaking some scenarios.
Codecov Report
@@ Coverage Diff @@
## main #2890 +/- ##
=======================================
Coverage 86.63% 86.64%
=======================================
Files 217 217
Lines 15531 15564 +33
=======================================
+ Hits 13456 13486 +30
- Misses 2075 2078 +3
|
|
@aboedo all tests passing 🎉 |
807253b to
aea4824
Compare
joshdholtz
left a comment
There was a problem hiding this comment.
A few small questions/nits but looks good to ship 👍
There was a problem hiding this comment.
Might be a nit but any reason why this is String instead of InitiationSource? 🤷♂️
There was a problem hiding this comment.
Good suggestion, changed.
There was a problem hiding this comment.
Oh I know why: this is used by ReceiptParser too, which doesn't have that type
There was a problem hiding this comment.
Why does this not need to remove the callback? When would this callback get removed? 🤔
Just want to make sure its not there for forever 🤷♂️
There was a problem hiding this comment.
This case represents a situation where there's activity in the queue for an older, probably expired transaction for the same product.
A callback would only exist as a result of initiating a purchase. So the assumption here is that:
a) the message in the queue here was not for the purchase we initiated, but rather some old activity in the queue. This is why we check the transaction date.
b) the queue will eventually post a message for the purchase that we did initiate.
But we could write comments to make that very explicit here, it's delicate stuff
There was a problem hiding this comment.
This case represents a situation where there's activity in the queue for an older, probably expired transaction for the same product.
A callback would only exist as a result of initiating a purchase. So the assumption here is that:
a) the message in the queue here was not for the purchase we initiated, but rather some old activity in the queue. This is why we check the transaction date.
b) the queue will eventually post a message for the purchase that we did initiate.
But we could write comments to make that very explicit here, it's delicate stuff
There was a problem hiding this comment.
shouldn't we eventually post the transaction from 6 as a purchase?
There was a problem hiding this comment.
LOL yeah this is a bad refactor from me changing the test. clearMessages shouldn't be there.
|
looking great! left a question |
This adds tests and a fix for a scenario discovered by @aboedo and @mcastany. - Make a purchase of product_1 - Close app - Renewals happen in the background - Subscription expires - Open app, renewals are in the queue but not processed yet - Start a purchase of `product_1` (`SKPaymentQueue.add`) - StoreKit queue shows renewal from step 3 as finished, it's expired - SDK sees finished transaction in the queue for `product_1` - SDK sees completion block for `product_1`, considers it a successful `.purchase` - SDK posts receipt, `initiation_source: .purchase` 💥 - Backend replies with 422 because StoreKit hasn't processed the transaction from 6 The fix looks at the date when the completion block was added (the time `.purchase()` is called). If the transaction was created _before_ this, we know it didn't come from the actual purchase, and therefore it should be identified as `.queue`.
aea4824 to
3dc2c5b
Compare
3dc2c5b to
c2e8da0
Compare
| return self.purchaseCompleteCallbacksByProductID.modify { callbacks -> PurchaseCompletedBlock? in | ||
| guard let value = callbacks[transaction.productIdentifier] else { return nil } | ||
|
|
||
| if !transaction.hasKnownPurchaseDate || value.creationDate <= transaction.purchaseDate { |
There was a problem hiding this comment.
I know I'm late here but maybe we could extract this condition to a function transactionDateMatchCallbackDate, transactionMatchesCallback or something like that? Just so it's easier to read
_This release is compatible with Xcode 15 beta 6 and visionOS beta 3_ ### Bugfixes * `visionOS`: support for `Xcode 15 beta 6` (#2989) via NachoSoto (@NachoSoto) * `CachingProductsManager`: avoid crash when caching different products with same identifier (#2979) via NachoSoto (@NachoSoto) * `PurchasesOrchestrator`: disambiguate transactions from the queue (#2890) via NachoSoto (@NachoSoto) ### Performance Improvements * `StoreKit2TransactionListener`: handle transactions asynchronously (#2910) via NachoSoto (@NachoSoto) ### Other Changes * `Atomic`: avoid race conditions modifying dictionaries (#2981) via NachoSoto (@NachoSoto) * `Logging`: avoid logging "updating offerings" when request is cached (#2904) via NachoSoto (@NachoSoto) * `StoreKit2TransactionListener`: converted into an `actor` (#2909) via NachoSoto (@NachoSoto) * `Integration Tests`: added more observer mode tests (#2905) via NachoSoto (@NachoSoto) * Created `PostedTransactionCache` (#2911) via NachoSoto (@NachoSoto) * `IntroEligibility`: changed products to `Set<String>` (#2976) via NachoSoto (@NachoSoto) * `AdServices`: Rename `postAdServicesTokenIfNeeded()` to `postAdServicesTokenOncePerInstallIfNeeded()` (#2968) via Josh Holtz (@joshdholtz) * `SK1StoreProduct`: changed `productType` warning to debug (#2957) via NachoSoto (@NachoSoto) * `PrivacyInfo.xcprivacy`: added `UserDefaults` to access API types (#2913) via NachoSoto (@NachoSoto) * `Integration Tests`: new test to verify that SK1 purchases don't leave SK2 unfinished transactions (#2906) via NachoSoto (@NachoSoto) * `Logging`: log entire cache key with verbose logs (#2888) via NachoSoto (@NachoSoto) * `StoreProduct`: added test covering warning log (#2897) via NachoSoto (@NachoSoto) * `CustomEntitlementComputation`: use custom API key (#2879) via Toni Rico (@tonidero) * `CachingProductsManager`: removed duplicate log and added tests (#2898) via NachoSoto (@NachoSoto) * `Xcode 15 beta 5`: fixed test compilation (#2885) via NachoSoto (@NachoSoto) --------- Co-authored-by: NachoSoto <ignaciosoto90@gmail.com>
… downgrades Fixes #3020. This essentially reverts #2890. As shown in #3020, downgrades are reported with the same transaction identifier as the original transaction. Therefore our approach in #2890 is invalid. We considered checking whether the `SKPayment` in the `SKPaymentTransaction` matches the one added to the queue as a way to disambiguate these transactions, but it doesn't. So we have no way of telling the difference between queue transactions and purchases. I've left the original tests as a way to at least document this behavior.
… downgrades (#3028) Fixes #3020. This essentially reverts #2890. As shown in #3020, downgrades are reported with the same transaction identifier as the original transaction. Therefore our approach in #2890 is invalid. We considered checking whether the `SKPayment` in the `SKPaymentTransaction` matches the one added to the queue as a way to disambiguate these transactions, but it doesn't. So we have no way of telling the difference between queue transactions and purchases. I've left the original tests as a way to at least document this behavior.
) This adds tests and a fix for a scenario discovered by @aboedo and @mcastany. ### Timeline: - Make a purchase of product_1 - Close app - Renewals happen in the background - Subscription expires - Open app, renewals are in the queue but not processed yet - Start a purchase of `product_1` (`SKPaymentQueue.add`) - StoreKit queue shows renewal from step 3 as finished, it's expired - SDK sees finished transaction in the queue for `product_1` - SDK sees completion block for `product_1`, considers it a successful `.purchase` - SDK posts receipt, `initiation_source: .purchase` 💥 - Backend replies with 422 because StoreKit hasn't processed the transaction from 6 ### Fix: The fix looks at the date when the completion block was added (the time `.purchase()` is called). If the transaction was created _before_ this, we know it didn't come from the actual purchase, and therefore it should be identified as `.queue`.
_This release is compatible with Xcode 15 beta 6 and visionOS beta 3_ ### Bugfixes * `visionOS`: support for `Xcode 15 beta 6` (#2989) via NachoSoto (@NachoSoto) * `CachingProductsManager`: avoid crash when caching different products with same identifier (#2979) via NachoSoto (@NachoSoto) * `PurchasesOrchestrator`: disambiguate transactions from the queue (#2890) via NachoSoto (@NachoSoto) ### Performance Improvements * `StoreKit2TransactionListener`: handle transactions asynchronously (#2910) via NachoSoto (@NachoSoto) ### Other Changes * `Atomic`: avoid race conditions modifying dictionaries (#2981) via NachoSoto (@NachoSoto) * `Logging`: avoid logging "updating offerings" when request is cached (#2904) via NachoSoto (@NachoSoto) * `StoreKit2TransactionListener`: converted into an `actor` (#2909) via NachoSoto (@NachoSoto) * `Integration Tests`: added more observer mode tests (#2905) via NachoSoto (@NachoSoto) * Created `PostedTransactionCache` (#2911) via NachoSoto (@NachoSoto) * `IntroEligibility`: changed products to `Set<String>` (#2976) via NachoSoto (@NachoSoto) * `AdServices`: Rename `postAdServicesTokenIfNeeded()` to `postAdServicesTokenOncePerInstallIfNeeded()` (#2968) via Josh Holtz (@joshdholtz) * `SK1StoreProduct`: changed `productType` warning to debug (#2957) via NachoSoto (@NachoSoto) * `PrivacyInfo.xcprivacy`: added `UserDefaults` to access API types (#2913) via NachoSoto (@NachoSoto) * `Integration Tests`: new test to verify that SK1 purchases don't leave SK2 unfinished transactions (#2906) via NachoSoto (@NachoSoto) * `Logging`: log entire cache key with verbose logs (#2888) via NachoSoto (@NachoSoto) * `StoreProduct`: added test covering warning log (#2897) via NachoSoto (@NachoSoto) * `CustomEntitlementComputation`: use custom API key (#2879) via Toni Rico (@tonidero) * `CachingProductsManager`: removed duplicate log and added tests (#2898) via NachoSoto (@NachoSoto) * `Xcode 15 beta 5`: fixed test compilation (#2885) via NachoSoto (@NachoSoto) --------- Co-authored-by: NachoSoto <ignaciosoto90@gmail.com>
… downgrades (#3028) Fixes #3020. This essentially reverts #2890. As shown in #3020, downgrades are reported with the same transaction identifier as the original transaction. Therefore our approach in #2890 is invalid. We considered checking whether the `SKPayment` in the `SKPaymentTransaction` matches the one added to the queue as a way to disambiguate these transactions, but it doesn't. So we have no way of telling the difference between queue transactions and purchases. I've left the original tests as a way to at least document this behavior.
This adds tests and a fix for a scenario discovered by @aboedo and @mcastany.
Timeline:
product_1(SKPaymentQueue.add)product_1product_1, considers it a successful.purchaseinitiation_source: .purchase💥Fix:
The fix looks at the date when the completion block was added (the time
.purchase()is called).If the transaction was created before this, we know it didn't come from the actual purchase, and therefore it should be identified as
.queue.