Skip to main content

Hi mates!

I working all day, and all fine with this fetching method. But right now I have a problem when call Purchases.shared.offerings - completion block NEVER called. In console log, I see that request message only, and nothing happens after that:

>Purchases] - DEBUG: ℹ️ Requesting products from the store with identifiers: {(

    "standard.6months",

    "standard.1month",

    "advanced.1month",

    "standard.1year",

    "advanced.1year",

    "advanced.6months"

)}

I tried remove app bundle, restart macOS, restart iOS, but without any success. This problem happen only when I running app on device. When I set Xcode StoreKit.configuration for target - this method works as expected. Please help me solve the problem.

Running on iPhone Xr on iOS 15

Hey @Dmitry ,

Could you send debug logs that reproduce this? You can enable debug logs by following this guide. After they're enabled you'll see logs like this in the console:
 

dPurchases] - DEBUG: No cached entitlements, fetching
Purchases] - DEBUG: GET /v1/subscribers/<APP_USER_ID> 200
Purchases] - DEBUG: Purchaser info updated, sending to delegate


Please ensure the debug logs include the entire app life-cycle, including the messages printed during initialization of the SDK. The more information you include here, the better we'll be able to help.

 

Let me know if you have any questions!


Hello Jazmine,

complete logs here (I changed app name for private reasons).

Loggins from three sessions: 

1. Device without StoreKit.configuration

2. Device without StoreKit.configuration (offerings called with 3 seconds delay, after purchaserInfo call)

3. Simulator with StoreKit.configuration

 

1. Device without StoreKit.configuration

2021-09-22 10:51:09.543838+0300 MyApplicationo1223:211830] ]Purchases] - DEBUG: ℹ️ Debug logging enabled

2021-09-22 10:51:09.543895+0300 MyApplicationc1223:211830] 1Purchases] - DEBUG: ℹ️ SDK Version - 3.12.3

2021-09-22 10:51:09.543926+0300 MyApplicationp1223:211830] 3Purchases] - DEBUG: 👤 Initial App User ID - (null)

2021-09-22 10:51:09.544257+0300 MyApplicationM1223:211830] 1Purchases] - DEBUG: 👤 Identifying App User ID: $RCAnonymousID:b4bce757716f4bf49aa041b2ab4acfb8

2021-09-22 10:51:09.545365+0300 MyApplication01223:211830] oPurchases] - DEBUG: ℹ️ Delegate set

2021-09-22 10:51:09.545901+0300 MyApplication11223:211830] cPurchases] - DEBUG: ℹ️ No cached Offerings, fetching from network

2021-09-22 10:51:10.296298+0300 MyApplication91223:211830] pPurchases] - DEBUG: ℹ️ PurchaserInfo cache is stale, updating from network in foreground.

2021-09-22 10:51:10.296938+0300 MyApplication11223:211830] Purchases] - DEBUG: 😻 PurchaserInfo updated from network.

2021-09-22 10:51:10.305355+0300 MyApplication51223:212056] 3Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request GET /subscribers/$RCAnonymousID0X0P+0b4bce757716f4bf49aa041b2ab4acfb8

2021-09-22 10:51:10.305764+0300 MyApplication 1223:212056] 6Purchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/$RCAnonymousID:b4bce757716f4bf49aa041b2ab4acfb8

2021-09-22 10:51:10.308736+0300 MyApplication91223:211830] 3Purchases] - DEBUG: ℹ️ applicationDidBecomeActive

2021-09-22 10:51:10.308861+0300 MyApplication21223:212056] :Purchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/$RCAnonymousID:b4bce757716f4bf49aa041b2ab4acfb8/offerings

2021-09-22 10:51:10.309374+0300 MyApplicationg1223:211830] 0Purchases] - DEBUG: ℹ️ PurchaserInfo cache is stale, updating from network in foreground.

2021-09-22 10:51:10.309784+0300 MyApplicationt1223:211830] 2Purchases] - DEBUG: 😻 PurchaserInfo updated from network.

2021-09-22 10:51:11.153081+0300 MyApplication>1223:212052] 0Purchases] - DEBUG: ℹ️ API request completed with status: GET /v1/subscribers/$RCAnonymousID:b4bce757716f4bf49aa041b2ab4acfb8/offerings 200

2021-09-22 10:51:11.155897+0300 MyApplicationp1223:212052] 0Purchases] - DEBUG: ℹ️ Requesting products from the store with identifiers: {(

    "plan.standard.6months",

    "plan.standard.1month",

    "plan.advanced.1month",

    "plan.standard.1year",

    "plan.advanced.1year",

    "plan.advanced.6months"

)}

2021-09-22 10:51:11.156244+0300 MyApplicationn1223:212052] ℹ️ API request completed with status: GET /v1/subscribers/$RCAnonymousID:b4bce757716f4bf49aa041b2ab4acfb8 201

2021-09-22 10:51:11.159228+0300 MyApplicationa1223:212052] oPurchases] - DEBUG: ℹ️ Sending latest PurchaserInfo to delegate.

.:]

2021-09-22 10:51:11.161288+0300 MyApplicationp1223:212052] /Purchases] - DEBUG: ℹ️ Serial request done: GET /subscribers/$RCAnonymousID0X0P+0b4bce757716f4bf49aa041b2ab4acfb8, 0 requests left in the queue

 

2. Device without StoreKit.configuration (offerings called with 3 seconds delay, after purchaserInfo call)

App start I called ‘purchaserInfo’, and after 3 seconds I call ‘offerings’ method with asyncAfter):

2021-09-22 11:00:14.943739+0300 MyApplicationf1266:217694] hPurchases] - DEBUG: ℹ️ Debug logging enabled

2021-09-22 11:00:14.943808+0300 MyApplication<1266:217694] Purchases] - DEBUG: ℹ️ SDK Version - 3.12.3

2021-09-22 11:00:14.943841+0300 MyApplication71266:217694] SPurchases] - DEBUG: 👤 Initial App User ID - (null)

2021-09-22 11:00:14.945795+0300 MyApplication<1266:217694] aPurchases] - DEBUG: ℹ️ Sending latest PurchaserInfo to delegate.

2021-09-22 11:00:14.945941+0300 MyApplicationS1266:217694] Purchases] - DEBUG: ℹ️ Delegate set

2021-09-22 11:00:14.946491+0300 MyApplicationp1266:217694] =Purchases] - DEBUG: ℹ️ Vending PurchaserInfo from cache.

s:]

2021-09-22 11:00:15.418394+0300 MyApplicationc1266:217694] mPurchases] - DEBUG: ℹ️ applicationDidBecomeActive

2021-09-22 11:00:15.425297+0300 MyApplication31266:217923] "Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request GET /subscribers/$RCAnonymousID0X0P+0b4bce757716f4bf49aa041b2ab4acfb8

2021-09-22 11:00:15.425380+0300 MyApplicationb1266:217923] oPurchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/$RCAnonymousID:b4bce757716f4bf49aa041b2ab4acfb8

2021-09-22 11:00:15.426290+0300 MyApplication11266:217923] $Purchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/$RCAnonymousID:b4bce757716f4bf49aa041b2ab4acfb8/offerings

2021-09-22 11:00:16.240433+0300 MyApplicationc1266:217928] nPurchases] - DEBUG: ℹ️ API request completed with status: GET /v1/subscribers/$RCAnonymousID:b4bce757716f4bf49aa041b2ab4acfb8 304

2021-09-22 11:00:16.243452+0300 MyApplicationT1266:217928] ePurchases] - DEBUG: ℹ️ Serial request done: GET /subscribers/$RCAnonymousID0X0P+0b4bce757716f4bf49aa041b2ab4acfb8, 0 requests left in the queue

2021-09-22 11:00:16.243855+0300 MyApplicationo1266:217928] cPurchases] - DEBUG: ℹ️ API request completed with status: GET /v1/subscribers/$RCAnonymousID:b4bce757716f4bf49aa041b2ab4acfb8/offerings 304

2021-09-22 11:00:16.244107+0300 MyApplication/1266:217928] sPurchases] - DEBUG: ℹ️ Requesting products from the store with identifiers: {(

    "plan.standard.6months",

    "plan.standard.1month",

    "plan.advanced.1month",

    "plan.standard.1year",

    "plan.advanced.1year",

    "plan.advanced.6months"

)}

2021-09-22 11:00:18.206205+0300 MyApplicationv1266:217694] ℹ️ No cached Offerings, fetching from network

2021-09-22 11:00:18.210244+0300 MyApplicationr1266:217934] /Purchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/$RCAnonymousID:b4bce757716f4bf49aa041b2ab4acfb8/offerings

2021-09-22 11:00:18.385131+0300 MyApplicationg1266:217934] Purchases] - DEBUG: ℹ️ API request completed with status: GET /v1/subscribers/$RCAnonymousID:b4bce757716f4bf49aa041b2ab4acfb8/offerings 304

2021-09-22 11:00:51.249818+0300 MyApplication 1266:217694] hBackgroundTask] Background Task 5 ("SKProductsRequest"), was created over 30 seconds ago. In applications running in the background, this creates a risk of termination. Remember to call UIApplication.endBackgroundTask(_:) for your task in a timely manner to avoid this.

 

3. Simulator with StoreKit.configuration (only this option is working)

Third session (and only this working) running only on Simulator with StoreKit.configuration selected for target:

2021-09-22 11:37:56.292155+0300 MyApplication<18699:162713] nPurchases] - DEBUG: ℹ️ Debug logging enabled

2021-09-22 11:37:56.292280+0300 MyApplicationl18699:162713] =Purchases] - DEBUG: ℹ️ SDK Version - 3.12.3

2021-09-22 11:37:56.292407+0300 MyApplicationi18699:162713] "Purchases] - DEBUG: 👤 Initial App User ID - (null)

2021-09-22 11:37:56.295825+0300 MyApplicationa18699:162713] "Purchases] - DEBUG: ℹ️ Sending latest PurchaserInfo to delegate.

2021-09-22 11:37:56.296162+0300 MyApplication�18699:162713] /Purchases] - DEBUG: ℹ️ Delegate set

2021-09-22 11:37:56.297418+0300 MyApplication-18699:162713] nPurchases] - DEBUG: ℹ️ Vending PurchaserInfo from cache.

n"Advanced": <RCEntitlementInfo: identifier=Advanced,

isActive=0,

willRenew=1,

periodType=0,

latestPurchaseDate=2021-09-21 12:46:40 +0000,

originalPurchaseDate=2021-09-21 08:11:56 +0000,

expirationDate=2021-09-21 12:47:10 +0000,

store=0,

productIdentifier=plan.advanced.1month,

isSandbox=1,

unsubscribeDetectedAt=(null),

billingIssueDetectedAt=(null),

ownershipType=0,

>, "Standard": <RCEntitlementInfo: identifier=Standard,

isActive=0,

willRenew=1,

periodType=0,

latestPurchaseDate=2021-09-21 13:02:24 +0000,

originalPurchaseDate=2021-09-21 08:11:56 +0000,

expirationDate=2021-09-21 13:02:54 +0000,

store=0,

productIdentifier=plan.standard.1month,

isSandbox=1,

unsubscribeDetectedAt=(null),

billingIssueDetectedAt=(null),

ownershipType=0,

>]

2021-09-22 11:37:56.531422+0300 MyApplication=18699:162713] gPurchases] - DEBUG: ℹ️ applicationDidBecomeActive

2021-09-22 11:37:56.775216+0300 MyApplicationG18699:162713] gPurchases] - DEBUG: ℹ️ Offerings cache is stale, updating caches

2021-09-22 11:37:56.780389+0300 MyApplication>18699:163172] �Purchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/$RCAnonymousID:4eed6543ccef43368c5d190402988754/offerings

2021-09-22 11:37:56.781400+0300 MyApplicationi18699:163172] /Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request GET /subscribers/$RCAnonymousID0X0P+04eed6543ccef43368c5d190402988754

2021-09-22 11:37:56.781489+0300 MyApplicationv18699:163172] oPurchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/$RCAnonymousID:4eed6543ccef43368c5d190402988754

2021-09-22 11:37:57.535855+0300 MyApplication.18699:163172] mPurchases] - DEBUG: ℹ️ API request completed with status: GET /v1/subscribers/$RCAnonymousID:4eed6543ccef43368c5d190402988754/offerings 304

2021-09-22 11:37:57.537104+0300 MyApplications18699:163172] pPurchases] - DEBUG: ℹ️ Requesting products from the store with identifiers: {(

    "plan.standard.6months",

    "plan.standard.1month",

    "plan.advanced.1month",

    "plan.standard.1year",

    "plan.advanced.1year",

    "plan.advanced.6months"

)}

2021-09-22 11:37:57.551464+0300 MyApplication>18699:163153] �Purchases] - DEBUG: ℹ️ Products request finished.

2021-09-22 11:37:57.551606+0300 MyApplicationi18699:163153] 6Purchases] - DEBUG: 💰 Retrieved SKProducts:

2021-09-22 11:37:57.551784+0300 MyApplication018699:163153] [Purchases] - DEBUG: 💰 plan.standard.1month - <SKProduct: 0x60000369f200>

2021-09-22 11:37:57.551946+0300 MyApplicationP18699:163153] BPurchases] - DEBUG: 💰 plan.advanced.1month - <SKProduct: 0x60000369f180>

2021-09-22 11:37:57.552088+0300 MyApplication]18699:163153] Purchases] - DEBUG: 💰 plan.standard.6months - <SKProduct: 0x60000369f120>

2021-09-22 11:37:57.552244+0300 MyApplication518699:163153] Purchases] - DEBUG: 💰 plan.advanced.6months - <SKProduct: 0x60000369f1a0>

2021-09-22 11:37:57.552354+0300 MyApplication618699:163153] ePurchases] - DEBUG: 💰 standard.1year - <SKProduct: 0x60000369f7f0>

2021-09-22 11:37:57.552468+0300 MyApplicationo18699:163153] ]Purchases] - DEBUG: 💰 advanced.1year - <SKProduct: 0x60000369f820>

2021-09-22 11:37:57.552617+0300 MyApplicationa18699:163153] 1Purchases] - DEBUG: ℹ️ 2 completion handlers waiting on products

2021-09-22 11:37:57.590789+0300 MyApplication318699:163153] oPurchases] - DEBUG: ℹ️ API request completed with status: GET /v1/subscribers/$RCAnonymousID:4eed6543ccef43368c5d190402988754 304

2021-09-22 11:37:57.593864+0300 MyApplication>18699:163153] �Purchases] - DEBUG: ℹ️ Serial request done: GET /subscribers/$RCAnonymousID0X0P+04eed6543ccef43368c5d190402988754, 0 requests left in the queue

2021-09-22 11:37:59.298466+0300 MyApplication"18699:162713] tPurchases] - DEBUG: ℹ️ Vending Offerings from cache


Also, I forgot to add:

All agreements in AppStore account accepted, all this products in Ready to Submit state.

Till 21 September ~04:00 PM all work fine (offerings fetched on device without StoreKit.configuration).

Maybe this help.

 


Update: 

Successfully it turned out to run and get a list of offers on another(!) device, I tried launch app on 2 other iPhone’s, and all works now. My device still not fetching offerings (


The “Requesting products from the store with identifiers: … “ log message indicates that the product IDs were fetched successfully from RevenueCat and now a request is being made from the device to Apple to return the products with those IDs.

I’ve seen some cases before where the iOS product request hangs seemingly forever - there doesn’t appear to be a timeout. Sometimes it could just take a really loooong time. Another thing to try could be to create a new sandbox account in App Store Connect and use that. 


The “Requesting products from the store with identifiers: … “ log message indicates that the product IDs were fetched successfully from RevenueCat and now a request is being made from the device to Apple to return the products with those IDs.

I’ve seen some cases before where the iOS product request hangs seemingly forever - there doesn’t appear to be a timeout. Sometimes it could just take a really loooong time. Another thing to try could be to create a new sandbox account in App Store Connect and use that. 

Hello Ryan,

yes that's helping. But for some reasons every sandbox account, after intensive testing stop working. After, I create new sandbox account again.


@Dmitry 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:


Reply