Skip to content

ReceiptFetcher: throttle receipt refreshing to avoid StoreKit throttle errors#2146

Merged
NachoSoto merged 1 commit into
mainfrom
receipt-fetcher-always-throttle
Dec 15, 2022
Merged

ReceiptFetcher: throttle receipt refreshing to avoid StoreKit throttle errors#2146
NachoSoto merged 1 commit into
mainfrom
receipt-fetcher-always-throttle

Conversation

@NachoSoto

@NachoSoto NachoSoto commented Dec 13, 2022

Copy link
Copy Markdown
Contributor

Fixes #2116.

Depends on #2134, #2144, #2145.

We've known that, especially for sandbox accounts with lots of purchases, the SDK can get flooded with a lot of transactions to process at once.
I've been making some improvements for this (like #2115).

Another consequence of this behavior, is that we can end up failing due to StoreKit throttling us (see #2116):

2022-12-03 12:31:58.670892+0100 app[673:61074] <SKReceiptRefreshRequest: 0x283edc860>: Finished refreshing receipt with error: Error Domain=ASDErrorDomain Code=603 "Request throttled" UserInfo={NSLocalizedFailureReason=Unified receipt is valid and current, NSLocalizedDescription=Request throttled, AMSServerErrorCode=0}

This change avoids that by skipping the refresh if less than 2 seconds have elapsed. I chose 2 to make this a low-ish risk change, with a huge benefit for multiple semi-concurrent requests coming from a big transaction queue.

@NachoSoto NachoSoto added the pr:fix A bug fix label Dec 13, 2022
@NachoSoto NachoSoto requested a review from a team December 13, 2022 18:15
@NachoSoto NachoSoto force-pushed the receipt-fetcher-always-throttle branch from de76eb9 to c442ad3 Compare December 13, 2022 19:15
@NachoSoto NachoSoto changed the base branch from main to async-await December 13, 2022 19:19
@NachoSoto NachoSoto force-pushed the receipt-fetcher-always-throttle branch from c442ad3 to 4e3348d Compare December 13, 2022 19:19
Comment thread Sources/Purchasing/ReceiptFetcher.swift Outdated
Comment on lines 45 to 54

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

makes sense. I wonder if a more reliable way of doing this would be to throttle unless we've had a response for the last request, i.e.: there are no requests in flight.

Do we know from the logs if for the customers that encountered this, they were throttled while a refresh was in flight or they were throttled after successful but frequent requests finished?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

makes sense. I wonder if a more reliable way of doing this would be to throttle unless we've had a response for the last request, i.e.: there are no requests in flight.

In most of these cases we're not doing concurrent requests, because we handle transactions linearly (see the example log in #2116). The problem is that we're refreshing it multiple times every second.

Do we know from the logs if for the customers that encountered this, they were throttled while a refresh was in flight or they were throttled after successful but frequent requests finished?

See log:

DEBUG: ℹ️ PaymentQueue updatedTransaction: product2 2000000218313433 2000000042575785 1
DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
DEBUG: ℹ️ PaymentQueue updatedTransaction: product2 2000000218320027 2000000042575785 1
DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
DEBUG: ℹ️ PaymentQueue updatedTransaction: product2 2000000218327443 2000000042575785 1
DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
DEBUG: ℹ️ PaymentQueue updatedTransaction: product2 2000000218334901 2000000042575785 1
DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
DEBUG: ℹ️ PaymentQueue updatedTransaction: product2 2000000218342186 2000000042575785 1
DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
DEBUG: ℹ️ PaymentQueue updatedTransaction: product2 2000000218353996 2000000042575785 1
DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
DEBUG: ℹ️ PaymentQueue updatedTransaction: product2 2000000218362596 2000000042575785 1
DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
DEBUG: ℹ️ PaymentQueue updatedTransaction: product2 2000000218370255 2000000042575785 1
DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
DEBUG: ℹ️ PaymentQueue updatedTransaction: product2 2000000218377794 2000000042575785 1
DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
<SKReceiptRefreshRequest: 0x283edc860>: Finished refreshing receipt with error: Error Domain=ASDErrorDomain Code=603 "Request throttled" UserInfo={NSLocalizedFailureReason=Unified receipt is valid and current, NSLocalizedDescription=Request throttled, AMSServerErrorCode=0}
DEBUG: ℹ️ Loaded receipt from url file:///private/var/mobile/Containers/Data/Application/5E49D650-1DE9-40C7-A20C-147D6C8718F8/StoreKit/sandboxReceipt

All those happen within the same second.

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

that highlights what I mean, though - we don't wait until we get the response from SKReceiptRefreshRequest before allowing for the next request to start, right? the logs there show a single finish

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Ooooh I see what you're saying.
Okay, I think maybe a better fix would be to reuse the completion block for concurrent receipt requests instead of throttling them.

That's what you have in mind too?

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

chatted about this offline - we already have a mechanism for this, it's just not enough if the receipt request finishes quickly.

Comment thread Sources/Purchasing/ReceiptFetcher.swift Outdated
Comment on lines 45 to 54

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

chatted about this offline - we already have a mechanism for this, it's just not enough if the receipt request finishes quickly.

@NachoSoto

Copy link
Copy Markdown
Contributor Author

This will help a lot prevent receipt refresh errors. Will merge once #2134 and #2145 are approved.

NachoSoto added a commit that referenced this pull request Dec 15, 2022
)

This would have given more visibility into the need for #2146.
Base automatically changed from async-await to main December 15, 2022 16:51
@NachoSoto NachoSoto force-pushed the receipt-fetcher-always-throttle branch from 4e3348d to 5c5d7c0 Compare December 15, 2022 17:02
@NachoSoto NachoSoto enabled auto-merge (squash) December 15, 2022 17:04
@NachoSoto NachoSoto merged commit 50f906e into main Dec 15, 2022
@NachoSoto NachoSoto deleted the receipt-fetcher-always-throttle branch December 15, 2022 17:14
NachoSoto pushed a commit that referenced this pull request Dec 15, 2022
**This is an automatic release.**

### Bugfixes
* Fix sending presentedOfferingIdentifier in StoreKit2 (#2156) via Toni
Rico (@tonidero)
* `ReceiptFetcher`: throttle receipt refreshing to avoid `StoreKit`
throttle errors (#2146) via NachoSoto (@NachoSoto)
### Other Changes
* Added integration and unit tests to verify observer mode behavior
(#2069) via NachoSoto (@NachoSoto)
* Created `ClockType` and `TestClock` to be able to mock time (#2145)
via NachoSoto (@NachoSoto)
* Extracted `asyncWait` to poll `async` conditions in tests (#2134) via
NachoSoto (@NachoSoto)
* `StoreKitRequestFetcher`: added log when starting/ending requests
(#2151) via NachoSoto (@NachoSoto)
* `CI`: fixed `PurchaseTester` deployment (#2147) via NachoSoto
(@NachoSoto)
NachoSoto added a commit that referenced this pull request Jan 25, 2023
…nlyIfEmpty` after a purchase

We've had reports of receipt fetching throttling errors (#2116). #2146 improved this by throttling receipt refreshing.
However, we can avoid this altogether by not refreshing the receipt unless it's empty.

The main reason being that the backend will automatically refresh the receipt using `/verifyReceipt`, so it doesn't matter if the receipt we post is slightly out of date.
NachoSoto added a commit that referenced this pull request Jan 25, 2023
…nlyIfEmpty` after a purchase (#2245)

We've had reports of receipt fetching throttling errors (#2116). #2146
improved this by throttling receipt refreshing.
However, we can avoid this altogether by not refreshing the receipt
unless it's empty.

The main reason being that the backend will automatically refresh the
receipt using `/verifyReceipt`, so it doesn't matter if the receipt we
post is slightly out of date.
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.

Error in first call, the user tries to purchase a product

2 participants