Solved

iOS 15/Xcode 13 [[RCPurchases sharedPurchases] offeringsWithCompletionBlock:] is never called

  • 24 September 2021
  • 33 replies
  • 2148 views

Userlevel 1
Badge +3

iPadOS 15 running app from Xcode fails to return any products. Restore Purchases also fails to return.

Rebooting iPad allows it to work first time only.

This issue is specifically relating to auto-renewing subscriptions.

Built using Xcode Version 13.0 (13A233)

No issue with same code on iOS 14.

Success and failure logs follow.

Success:

2021-09-24 16:17:50.773181+0800 ZeroTime[345:4478] [Purchases] - DEBUG: ℹ️ Debug logging enabled
2021-09-24 16:17:50.773293+0800 ZeroTime[345:4478] [Purchases] - DEBUG: ℹ️ SDK Version - 3.12.4
2021-09-24 16:17:50.773336+0800 ZeroTime[345:4478] [Purchases] - DEBUG: 👤 Initial App User ID - (null)
2021-09-24 16:17:50.777445+0800 ZeroTime[345:4478] [Purchases] - DEBUG: ℹ️ Sending latest PurchaserInfo to delegate.
2021-09-24 16:17:50.778858+0800 ZeroTime[345:4478] didReceiveUpdatedPurchaserInfo: <PurchaserInfo
 originalApplicationVersion: (null),
 latestExpirationDate: (null)
 activeEntitlements: {
},
 activeSubscriptions: {
},
 nonConsumablePurchases: {(
)},
 requestDate: 2021-09-24 08:12:16 +0000
 firstSeen: 2021-09-24 08:12:16 +0000,
originalAppUserId: $RCAnonymousID:cada631d501147efa13dd3dd44741b9c,
entitlements: {
},
> {
    originalAppUserId = "$RCAnonymousID:cada631d501147efa13dd3dd44741b9c";
    willRenew = No;
}
2021-09-24 16:17:50.778946+0800 ZeroTime[345:4478] [Purchases] - DEBUG: ℹ️ Delegate set
2021-09-24 16:17:51.070276+0800 ZeroTime[345:4478] [Purchases] - DEBUG: ℹ️ Vending PurchaserInfo from cache.
2021-09-24 16:17:51.070546+0800 ZeroTime[345:4478] purchaserInfo: <PurchaserInfo
 originalApplicationVersion: (null),
 latestExpirationDate: (null)
 activeEntitlements: {
},
 activeSubscriptions: {
},
 nonConsumablePurchases: {(
)},
 requestDate: 2021-09-24 08:12:16 +0000
 firstSeen: 2021-09-24 08:12:16 +0000,
originalAppUserId: $RCAnonymousID:cada631d501147efa13dd3dd44741b9c,
entitlements: {
},
>
2021-09-24 16:17:51.070670+0800 ZeroTime[345:4478] [Purchases] - DEBUG: ℹ️ applicationDidBecomeActive
2021-09-24 16:17:51.079287+0800 ZeroTime[345:4655] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request GET /subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c
2021-09-24 16:17:51.079500+0800 ZeroTime[345:4655] [Purchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/$RCAnonymousID:cada631d501147efa13dd3dd44741b9c
2021-09-24 16:17:51.081741+0800 ZeroTime[345:4655] [Purchases] - DEBUG: ℹ️ There's a request currently running and 0 requests left in the queue, queueing GET /subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c/offerings
2021-09-24 16:17:52.576457+0800 ZeroTime[345:4653] [Purchases] - DEBUG: ℹ️ API request completed with status: GET /v1/subscribers/$RCAnonymousID:cada631d501147efa13dd3dd44741b9c 304
2021-09-24 16:17:52.580989+0800 ZeroTime[345:4653] [Purchases] - DEBUG: ℹ️ Serial request done: GET /subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c, 1 requests left in the queue
2021-09-24 16:17:52.581240+0800 ZeroTime[345:4653] [Purchases] - DEBUG: ℹ️ Starting the next request in the queue, <RCHTTPRequest: httpMethod=GET
path=/subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c/offerings
requestBody=(null)
headers={
    Authorization = "Bearer vXpx...";
}
retried=0
>
2021-09-24 16:17:52.582667+0800 ZeroTime[345:4653] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request GET /subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c/offerings
2021-09-24 16:17:52.582820+0800 ZeroTime[345:4653] [Purchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/$RCAnonymousID:cada631d501147efa13dd3dd44741b9c/offerings
2021-09-24 16:17:52.993356+0800 ZeroTime[345:4652] [Purchases] - DEBUG: ℹ️ API request completed with status: GET /v1/subscribers/$RCAnonymousID:cada631d501147efa13dd3dd44741b9c/offerings 304
2021-09-24 16:17:52.994226+0800 ZeroTime[345:4652] [Purchases] - DEBUG: ℹ️ Requesting products from the store with identifiers: {(
    "io.smudge.ZeroTime.SUB.Yearly",
    "io.smudge.ZeroTime.SUB.Monthly"
)}
2021-09-24 16:17:52.998017+0800 ZeroTime[345:4652] [Purchases] - DEBUG: ℹ️ Serial request done: GET /subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c/offerings, 0 requests left in the queue
2021-09-24 16:17:53.062085+0800 ZeroTime[345:4652] [Purchases] - DEBUG: ℹ️ Products request finished.
2021-09-24 16:17:53.062174+0800 ZeroTime[345:4652] [Purchases] - DEBUG: 💰 Retrieved SKProducts: 
2021-09-24 16:17:53.062242+0800 ZeroTime[345:4652] [Purchases] - DEBUG: 💰 io.smudge.ZeroTime.SUB.Monthly - <SKProduct: 0x283cbdc10>
2021-09-24 16:17:53.062297+0800 ZeroTime[345:4652] [Purchases] - DEBUG: 💰 io.smudge.ZeroTime.SUB.Yearly - <SKProduct: 0x283cbd820>
2021-09-24 16:17:53.062345+0800 ZeroTime[345:4652] [Purchases] - DEBUG: ℹ️ 1 completion handlers waiting on products
2021-09-24 16:17:58.074549+0800 ZeroTime[345:4478] [Purchases] - DEBUG: ℹ️ Vending Offerings from cache


Failure: 

2021-09-24 16:13:05.996820+0800 ZeroTime[503:10344] [Purchases] - DEBUG: ℹ️ Debug logging enabled
2021-09-24 16:13:05.996935+0800 ZeroTime[503:10344] [Purchases] - DEBUG: ℹ️ SDK Version - 3.12.4
2021-09-24 16:13:05.996978+0800 ZeroTime[503:10344] [Purchases] - DEBUG: 👤 Initial App User ID - (null)
2021-09-24 16:13:06.000895+0800 ZeroTime[503:10344] [Purchases] - DEBUG: ℹ️ Sending latest PurchaserInfo to delegate.
2021-09-24 16:13:06.001788+0800 ZeroTime[503:10344] didReceiveUpdatedPurchaserInfo: <PurchaserInfo
 originalApplicationVersion: (null),
 latestExpirationDate: (null)
 activeEntitlements: {
},
 activeSubscriptions: {
},
 nonConsumablePurchases: {(
)},
 requestDate: 2021-09-24 08:12:16 +0000
 firstSeen: 2021-09-24 08:12:16 +0000,
originalAppUserId: $RCAnonymousID:cada631d501147efa13dd3dd44741b9c,
entitlements: {
},
> {
    originalAppUserId = "$RCAnonymousID:cada631d501147efa13dd3dd44741b9c";
    willRenew = No;
}
2021-09-24 16:13:06.001865+0800 ZeroTime[503:10344] [Purchases] - DEBUG: ℹ️ Delegate set
2021-09-24 16:13:06.280716+0800 ZeroTime[503:10344] [Purchases] - DEBUG: ℹ️ Vending PurchaserInfo from cache.
2021-09-24 16:13:06.280911+0800 ZeroTime[503:10344] purchaserInfo: <PurchaserInfo
 originalApplicationVersion: (null),
 latestExpirationDate: (null)
 activeEntitlements: {
},
 activeSubscriptions: {
},
 nonConsumablePurchases: {(
)},
 requestDate: 2021-09-24 08:12:16 +0000
 firstSeen: 2021-09-24 08:12:16 +0000,
originalAppUserId: $RCAnonymousID:cada631d501147efa13dd3dd44741b9c,
entitlements: {
},
>
2021-09-24 16:13:06.281064+0800 ZeroTime[503:10344] [Purchases] - DEBUG: ℹ️ applicationDidBecomeActive
2021-09-24 16:13:06.287826+0800 ZeroTime[503:10402] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request GET /subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c
2021-09-24 16:13:06.287919+0800 ZeroTime[503:10402] [Purchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/$RCAnonymousID:cada631d501147efa13dd3dd44741b9c
2021-09-24 16:13:06.290863+0800 ZeroTime[503:10402] [Purchases] - DEBUG: ℹ️ There's a request currently running and 0 requests left in the queue, queueing GET /subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c/offerings
2021-09-24 16:13:07.702613+0800 ZeroTime[503:10399] [Purchases] - DEBUG: ℹ️ API request completed with status: GET /v1/subscribers/$RCAnonymousID:cada631d501147efa13dd3dd44741b9c 304
2021-09-24 16:13:07.705077+0800 ZeroTime[503:10399] [Purchases] - DEBUG: ℹ️ Serial request done: GET /subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c, 1 requests left in the queue
2021-09-24 16:13:07.705201+0800 ZeroTime[503:10399] [Purchases] - DEBUG: ℹ️ Starting the next request in the queue, <RCHTTPRequest: httpMethod=GET
path=/subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c/offerings
requestBody=(null)
headers={
    Authorization = "Bearer vXpx...";
}
retried=0
>
2021-09-24 16:13:07.706122+0800 ZeroTime[503:10399] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request GET /subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c/offerings
2021-09-24 16:13:07.706187+0800 ZeroTime[503:10399] [Purchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/$RCAnonymousID:cada631d501147efa13dd3dd44741b9c/offerings
2021-09-24 16:13:08.111173+0800 ZeroTime[503:10422] [Purchases] - DEBUG: ℹ️ API request completed with status: GET /v1/subscribers/$RCAnonymousID:cada631d501147efa13dd3dd44741b9c/offerings 304
2021-09-24 16:13:08.111475+0800 ZeroTime[503:10422] [Purchases] - DEBUG: ℹ️ Requesting products from the store with identifiers: {(
    "io.smudge.ZeroTime.SUB.Yearly",
    "io.smudge.ZeroTime.SUB.Monthly"
)}
2021-09-24 16:13:08.111900+0800 ZeroTime[503:10422] [Purchases] - DEBUG: ℹ️ Serial request done: GET /subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c/offerings, 0 requests left in the queue
2021-09-24 16:13:12.926935+0800 ZeroTime[503:10344] [Purchases] - DEBUG: ℹ️ No cached Offerings, fetching from network
2021-09-24 16:13:12.963155+0800 ZeroTime[503:10422] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request GET /subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c/offerings
2021-09-24 16:13:12.963257+0800 ZeroTime[503:10422] [Purchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/$RCAnonymousID:cada631d501147efa13dd3dd44741b9c/offerings
2021-09-24 16:13:13.334771+0800 ZeroTime[503:10422] [Purchases] - DEBUG: ℹ️ API request completed with status: GET /v1/subscribers/$RCAnonymousID:cada631d501147efa13dd3dd44741b9c/offerings 304
2021-09-24 16:13:13.335316+0800 ZeroTime[503:10422] [Purchases] - DEBUG: ℹ️ Serial request done: GET /subscribers/$RCAnonymousID0X0P+0cada631d501147efa13dd3dd44741b9c/offerings, 0 requests left in the queue

 

icon

Best answer by smudge.io 28 October 2021, 00:26

View original

33 replies

Badge +2

My issue was caused by this.  The IOS upgrade turned out to be a red herring.

Badge +2

This issue is however happening to all of my production users who upgraded to iOS 15 (15.2 at the time of writing).   The Purchases.shared.offerings callback has always worked fine in iOS 14 and can run without issue on iOS 15 in the simulator, but when in production or testing on physical device the callback doesn’t fire (ie, not a sandbox account issue).  I noticed this when I checked the monthly report and all iOS purchases had stopped.  Upgraded from v3.11 to v3.14 but still had the same issue.  Could really use some help here if anyone was in the same situation and was able to resolve this problem.  Thanks in advance.

Badge +1

how to get latest receipt info in webhook after verification done by revenuecat

Thanks for letting us know!

Userlevel 1
Badge +3

This issue is resolved in iOS 15.1.

Userlevel 5
Badge +8

@Sinecan Anhammer 

Is this maybe the fix that it is now showing the error that is caused by the test environment of Apple?

 

Exactly right, the fix is to actually produce an error instead of waiting forever for Apple to return a value. 

 

I’d be happy to try it but could not make it clear to me how I should try it out in my flutter app. If necessary, I can surely try if you would be able to provide step by step instructions on how I should use this branch in the app.

I’m working on propagating this fix to Flutter, I will keep you posted. Thanks for offering to test! 

Userlevel 5
Badge +8

@smudge.io I believe I should have been more clear as to what the fix does: it only introduces a timeout to ensure that the method at least returns a value. The real fix needs to come from Apple and go into the OS itself, so this timeout (plus some logs) is the best we can do in the meantime. 

From the notes in the summary post

We worked on a patch to address this behavior. While we cannot fix the iOS bug ourselves, we’ve introduced a timeout to the SKProductsRequest, which should ensure that getOfferingsreturns a value (an error, in the case of this bug).

 

We’ve heard some people report that this issue is fixed in iOS 15.1, but I can’t verify that since I don’t have an account that reproduces the issue in the first place. 

Thanks for testing!! 

Hi @Andy@smudge.io@Andrew Edwards 

Is this maybe the fix that it is now showing the error that is caused by the test environment of Apple?

I’d be happy to try it but could not make it clear to me how I should try it out in my flutter app. If necessary, I can surely try if you would be able to provide step by step instructions on how I should use this branch in the app.

Userlevel 1
Badge +3

@Andy looks like it still occurs with release/3.12.8 and the existing failing account:


2021-10-20 13:43:54.096509+0800 SKProductsDemo[316:4690] [Purchases] - ERROR: 🍎‼️ SKProductsRequest took longer than 30 seconds, cancelling request and returning an empty set. This seems to be an App Store quirk. If this is happening to you consistently, you might want to try using a new Sandbox account. More information: https://rev.cat/skproductsrequest-hangs
2021-10-20 13:43:54.097286+0800 SKProductsDemo[316:4672] [Purchases] - ERROR: 🍎‼️ Error fetching offerings - Error Domain=RCPurchasesErrorDomain Code=23 "There's a problem with your configuration. None of the products registered in the RevenueCat dashboard could be fetched from App Store Connect (or the StoreKit Configuration file if one is being used). 
More information: https://rev.cat/why-are-offerings-empty" UserInfo={NSLocalizedDescription=There's a problem with your configuration. None of the products registered in the RevenueCat dashboard could be fetched from App Store Connect (or the StoreKit Configuration file if one is being used). 
More information: https://rev.cat/why-are-offerings-empty, readable_error_code=CONFIGURATION_ERROR}

Userlevel 5
Badge +8

@smudge.io @Sinecan Anhammer @Andrew Edwards I’ve made a fix for purchases-ios. 

It’s available here, and you can get it by using `purchases-ios` branch:

  • `main` branch, for purchases-ios v4 (currently v4 is in beta)
  • `release/3.12.8` if you’re using the v3 version. 

Since we’ve had a tough time trying to reproduce this bug, if you still have access to one of the accounts that reproduces it, would you mind trying out the solution and letting us know if it solves it? It would be immensely helpful. And earn you some swag 😉

 

I made a summary of what we know about the issue here:

 

Userlevel 5
Badge +8

@Andrew Edwards I feel ya. Working at RevenueCat, I’ve created more sandbox accounts than I’d like (over 70 as of writing), since I keep either messing them up or needing more for quick testing.

Since for testing I don’t really need apple’s emails, and email verification isn’t required, I just set up accounts under our domain name, but that don’t necessarily map to a real email account. Just mentioning in case it’s useful.

 

Badge

@Andy makes sense! And I agree about mixing accounts. Just to be clear I always kept the sandbox account specific to the sandbox environment and never signed into my normal Media/purchases account in settings with the sandbox account. My main applied has been the only one signed into production and in app stores. 
 

it’s annoying creating a new sandbox account since it means a new AppleID and setup in AppStore connect 😞

 

but I’ll give it a shot. Thanks for the info!

Userlevel 5
Badge +8

another thing to note is that it breaks all IAP for the entire device even production IAP for other apps. 

 

Ouch, that’s gotta be super annoying. 

I don’t think there’s much we can do about the bug, though, since it’s very much on Apple’s side. Especially since this seems to be affecting other, production apps. 

My advice, though, is to never mix production accounts with sandbox, i.e.: never make a purchase in a sandbox environment using your regular iCloud account, and vice versa. This could lead to issues, and in the past it even broke accounts. 

For your case, I think you should try the following steps: 

  1. Creating another, new sandbox account in App Store Connect
  2. Logging out of sandbox and even production in app store. 
  3. Rebooting the device
  4. Logging into regular app store using your production account in Settings → Your account → Media & Purchases
  5. Logging into the new sandbox account in Settings → App Store → Sandbox Account

That should (hopefully) return things to normal. 

I’m currently working on an update that will time out the `SKProductsRequest` after a while, and cancel it. I’m not sure it’ll fix the problem, though, since it does depend on `SKProductsRequest` behaving correctly, which it doesn’t seem to. But it should at least provide some clarity and ensure the SDK doesn’t hang, even if StoreKit itself is hanging. 

 

 

Badge

@Andy Yes I did. But it’s not working anymore lol. 
another thing to note is that it breaks all IAP for the entire device even production IAP for other apps. 
and another side effect is that all apps in the AppStore show as “Get” or “Buy” even for ones that I have already downloaded. Usually you’d see a cloud download button the App Store shows them as if you’ve NEVER downloaded them. I’m seeing it right now actually. Gonna do a reboot. And for extra context the sandbox account is currently signed out of right now. I signed out after I did the IAP last night after a couple hours I noticed other apps’ IAP not working or crashing their apps

Userlevel 5
Badge +8

@Andrew Edwards 

Thanks for reporting back! So did you end up signing in with the same sandbox account when you signed in again? 

Badge

hey @Andrew Edwards ! Thanks for reporting!

Is this happening with a sandbox account? Have you made any purchases with a production account? I’m still trying to find a pattern in terms of which accounts trigger this, and it seems like many of the folks who ran into this had used a production account for a sandbox purchase.

Have you tried the steps I outlined in the other ticket?

 

Yes it was a sandbox account. And it’s happened on all the iOS 15 betas I’ve been on when trying this. Even both the purchases-iOS SDK ObjC and the new swift one. 
 

Another note is I created the sandbox account during the summer so it wasn’t a carryover from iOS 14/AppStore connect. It was made during the new/summer/beta season. 
 

and yes, what just worked for me was signing out of the sandbox account in settings and trying the IAP again and this time it was able to fetch the products and allow me to sign in with the account and everything seems to work for now.

Userlevel 5
Badge +8

hey @Andrew Edwards ! Thanks for reporting!

Is this happening with a sandbox account? Have you made any purchases with a production account? I’m still trying to find a pattern in terms of which accounts trigger this, and it seems like many of the folks who ran into this had used a production account for a sandbox purchase.

Have you tried the steps I outlined in the other ticket?

 

Badge

I’ve actually been having the same issue for a while now, I even raised an issue https://github.com/RevenueCat/purchases-ios/issues/851
But after I rebooted my device it started working again. But a couple weeks later it started hanging again. 
I noticed it was breaking the YouTube app if I tried to get products in my own app then tried launching YouTube it would hang and crash YouTube.

Userlevel 5
Badge +8

@Sinecan Anhammer I replied on the other ticket, I hope that helps!

As far as I understand it, Apple has changed something and the RevenueCat API needs to be updated as well. This is a stopper for being able to submit the app for review to Apple. When should we expect a fix in API and how will it be communicated?

Userlevel 5
Badge +8

@smudge.io we created a support ticket for you, it includes a link to this post. You can use that to share it privately.

Thanks!! 🙌

Userlevel 1
Badge +3

@Andy sure, let me know how you would like me to share it, given that it contains sensitive information.

Userlevel 5
Badge +8

@smudge.io Did you end up creating a demo project that reproduces it? If so, would you mind sharing it with us? We’ve had a difficult time reproducing the issue, but we’d love to figure it out.

Also, we’ve released versions `3.12.6` (and made updates to our v4 beta in the `main` branch) that improve the SDK’s behavior for offerings in a couple of places. I don’t think they directly address the issue you were facing, but I’d still recommend updating.

Userlevel 1
Badge +3

Further information after building a demo project for Apple Feedback: FB9650399

When running the project as the original account in Settings | App Store | Sandbox Account and using the RevenueCat SDK, the product identifiers will only be returned the first time, until the device is rebooted. Using native StoreKit, also fails to return product identifiers after the initial RevenueCat SDK failure.

Using native StoreKit with the original account, it will consistently return product identifiers until the RevenueCat SDK is used, and then it will fail for both RevenueCat SDK and native StoreKit until reboot.

When running the project as a different account in Settings | App Store | Sandbox Account, after a reboot, the account consistently returns product identifiers using either RevenueCat or native StoreKit.

It seems as though something like a process is crashing when using the RevenueCat SDK, only when using the original account, that is not restarted until the iOS device is restarted.

This workaround is really helpful to document, thank you!

 

Also, @Andy found some places where completion blocks might not be called and he put a PR up: https://github.com/RevenueCat/purchases-ios/pull/879. I don’t think this helps your specific case (because iOS 14 works fine), but when it comes to different iOS versions I wouldn’t be entirely surprised if it did help somehow.

 

 

Reply