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.

Sign up for GitHub

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

Jump to bottom

Bug purchasing product #4020

Open
7 of 12 tasks
jesus-mg-ios opened this issue Jul 4, 2024 · 8 comments
Open
7 of 12 tasks

Bug purchasing product #4020

jesus-mg-ios opened this issue Jul 4, 2024 · 8 comments
Assignees
@aboedo
Labels
bug

Comments

@jesus-mg-ios
Copy link

Describe the bug

Users on a non-production environment (we don't know if it's happening in production) enter the paywall and then push the button to pay. Without showing the purchase sheet, RevenueCat says, "Oh, it's purchased." Then, the next screen appears. However, 2 or 3 seconds later, RevenueCat updates the status and says, "Hey, there's no subscription." If the user goes to pay again, the Apple sheet appears, prompting the user to enter the sandbox account credentials to complete the subscription payment.

  1. Environment
    1. Platform: iOS
    2. SDK version: 4.41.2
    3. StoreKit version:
      • StoreKit 1
      • StoreKit 2 (enabled with usesStoreKit2IfAvailable(true))
    4. OS version:
    5. Xcode version:
    6. Device and/or simulator:
      • Device
      • Simulator
    7. Environment:
      • Sandbox
      • TestFight
      • Production ?
    8. How widespread is the issue. Percentage of devices affected.
  2. Debug logs that reproduce the issue. Complete logs with Purchases.logLevel = .verbose will help us debug this issue.
INFO: ℹ️ Marking AdServices attribution token as synced for App User ID: USERID
Updating selectors after delegate addition failed with: Error Domain=NSCocoaErrorDomain Code=4099 
"The connection to service with pid 94 named com.apple.commcenter.coretelephony.xpc was invalidated from this process." 
UserInfo={NSDebugDescription=The connection to service with pid 94 named com.apple.commcenter.coretelephony.xpc was invalidated from this process.}
WARN: ⚠️ The appUserID passed to logIn is the same as the one already cached. No action will be taken.

attributes: ["$email": [SubscriberAttribute] key: $email value: [email protected] setTime: 2024-07-04 1:25:44 PM +0000]
INFO: ℹ️ Marking attributes as synced for App User ID: USERID:
attributes: ["$email": [SubscriberAttribute] key: $email value: [email protected] setTime: 2024-07-04 1:25:44 PM +0000]
WARN: ⚠️ The appUserID passed to logIn is the same as the one already cached. No action will be taken.

INFO: 💰 Finishing transaction '2000000645085987' for product 'app_product'
INFO: ℹ️ Marking attributes as synced for App User ID: USERID:
attributes: ["$email": [SubscriberAttribute] key: $email value: [email protected] setTime: 2024-07-04 1:25:44 PM +0000]

purchases delegate <RCPurchases: 0x10ce19050>, info <CustomerInfo:
originalApplicationVersion=1.0,
latestExpirationDate=Optional(2024-07-02 8:33:43 PM +0000),
activeEntitlements=[:],
activeSubscriptions=[:],
nonSubscriptions=[],
requestDate=2024-07-04 12:59:38 PM +0000,
firstSeen=2024-03-14 9:33:58 AM +0000,
originalAppUserId=$RCAnonymousID:f463ce6a0f994aa8be0090b42976aef8,
entitlements=["entitlement1": "<EntitlementInfo: \"\nidentifier=entitlement1,\nisActive=false,\nwillRenew=false,\nperiodType=PeriodType(rawValue: 0),\nlatestPurchaseDate=Optional(2024-06-06 9:40:33 AM +0000),\noriginalPurchaseDate=Optional(2024-03-14 9:40:33 AM +0000),\nexpirationDate=Optional(2024-06-12 9:44:08 AM +0000),\nstore=Store(rawValue: 3),\nproductIdentifier=prod_LCWjS9AccWbDa8,\nproductPlanIdentifier=null,\nisSandbox=true,\nunsubscribeDetectedAt=Optional(2024-06-12 9:44:08 AM +0000),\nbillingIssueDetectedAt=Optional(2024-06-06 9:42:12 AM +0000),\nownershipType=PurchaseOwnershipType(rawValue: 0),\nverification=VerificationResult.notRequested\n>", 
"entitlement2s": "<EntitlementInfo: \"\nidentifier=entitlement2s,\nisActive=false,\nwillRenew=false,\nperiodType=PeriodType(rawValue: 0),\nlatestPurchaseDate=Optional(2024-07-02 7:33:43 PM +0000),\noriginalPurchaseDate=Optional(2024-03-14 9:36:15 AM +0000),\nexpirationDate=Optional(2024-07-02 8:33:43 PM +0000),\nstore=Store(rawValue: 0),\nproductIdentifier=app_product,\nproductPlanIdentifier=null,\nisSandbox=true,\nunsubscribeDetectedAt=Optional(2024-07-02 7:37:14 PM +0000),\nbillingIssueDetectedAt=nil,\nownershipType=PurchaseOwnershipType(rawValue: 0),\nverification=VerificationResult.notRequested\n>"]
verification=VerificationResult.notRequested
>

ERROR: 😿‼️ One or more of the attributes sent could not be saved. ["$thirdId": "thirdId ID cannot be modified.", "$idfv": "IDFV cannot be modified."]
INFO: 💰 Finishing transaction '2000000645121224' for product 'app_product'
INFO: ℹ️ Marking attributes as synced for App User ID: USERID:
attributes: ["$email": [SubscriberAttribute] key: $email value: [email protected] setTime: 2024-07-04 1:25:44 PM +0000, "$thirdId": [SubscriberAttribute] key: $thirdId value: 1720099217062-3763104 setTime: 2024-07-04 1:25:46 PM +0000, "$idfa": [SubscriberAttribute] key: $idfa value: setTime: 2024-07-04 1:25:46 PM +0000, "$idfv": [SubscriberAttribute] key: $idfv value: IDFAVALUE setTime: 2024-07-04 1:25:46 PM +0000, "$ip": [SubscriberAttribute] key: $ip value: true setTime: 2024-07-04 1:25:46 PM +0000]

ERROR: 😿‼️ One or more of the attributes sent could not be saved. ["$idfv": "IDFV cannot be modified.", "$thirdId": "thirdId ID cannot be modified."]
INFO: 💰 Finishing transaction '2000000645149212' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645202848' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645178101' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645149211' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645121223' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645085986' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645202848' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645178101' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645149211' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645121223' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645085986' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645202848' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645178101' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645149211' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645121223' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645085986' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645202848' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645178101' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645149211' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645121223' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645085986' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645202848' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645178101' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645149211' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645121223' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645085986' for product 'app_product'
ERROR: 😿‼️ One or more of the attributes sent could not be saved. ["$thirdId": "thirdId ID cannot be modified.", "$idfv": "IDFV cannot be modified."]
INFO: 💰 Finishing transaction '2000000645178101' for product 'app_product'
INFO: ℹ️ Marking attributes as synced for App User ID: USERID:
attributes: ["$idfv": [SubscriberAttribute] key: $idfv value: IDFAVALUE setTime: 2024-07-04 1:25:46 PM +0000, "$email": [SubscriberAttribute] key: $email value: [email protected] setTime: 2024-07-04 1:25:44 PM +0000, "$thirdId": [SubscriberAttribute] key: $thirdId value: 1720099217062-3763104 setTime: 2024-07-04 1:25:46 PM +0000, "$idfa": [SubscriberAttribute] key: $idfa value: setTime: 2024-07-04 1:25:46 PM +0000, "$ip": [SubscriberAttribute] key: $ip value: true setTime: 2024-07-04 1:25:46 PM +0000]

ERROR: 😿‼️ One or more of the attributes sent could not be saved. ["$idfv": "IDFV cannot be modified.", "$thirdId": "thirdId ID cannot be modified."]
INFO: 💰 Finishing transaction '2000000645202849' for product 'app_product'
Tapped Buy
INFO: 💰 Purchasing Product 'app_product'
INFO: ℹ️ Marking attributes as synced for App User ID: USERID:
attributes: ["$thirdId": [SubscriberAttribute] key: $thirdId value: 1720099217062-3763104 setTime: 2024-07-04 1:25:46 PM +0000, "$ip": [SubscriberAttribute] key: $ip value: true setTime: 2024-07-04 1:25:46 PM +0000, "$idfa": [SubscriberAttribute] key: $idfa value: setTime: 2024-07-04 1:25:46 PM +0000, "$email": [SubscriberAttribute] key: $email value: [email protected] setTime: 2024-07-04 1:25:44 PM +0000, "$idfv": [SubscriberAttribute] key: $idfv value: IDFAVALUE setTime: 2024-07-04 1:25:46 PM +0000]

INFO: 😻💰 Purchased product - 'app_product'
Purchased ----> true  ----> public typealias PurchaseCompletedBlock = @MainActor @Sendable (RevenueCat.StoreTransaction?, RevenueCat.CustomerInfo?, RevenueCat.PublicError?, Bool) -> Void -> RevenueCat.PublicError is nil, Bool is false (User has no cancelled)

INFO: 💰 Finishing transaction '2000000645202848' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645178101' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645085986' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645121223' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645149211' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645202848' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645178101' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645085986' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645149211' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645202848' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645178101' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645149211' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645085986' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645121223' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645121223' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645149212' for product 'app_product'
INFO: 💰 Finishing transaction '2000000645202849' for product 'app_product'
ERROR: 😿‼️ The receipt is not valid. The purchased product was missing in the receipt. This is typically due to a bug in StoreKit.
WARN: ⚠️ Attempt to update CustomerInfo from network failed. The operation couldn’t be completed. (RevenueCat.BackendError error 0.)
Underlying error: The receipt is not valid. The purchased product was missing in the receipt. This is typically due to a bug in StoreKit.
ERROR: 😿‼️ The receipt is not valid. The purchased product was missing in the receipt. This is typically due to a bug in StoreKit.
ERROR: 😿‼️ The receipt is not valid. The purchased product was missing in the receipt. This is typically due to a bug in StoreKit.
WARN: ⚠️ Attempt to update CustomerInfo from network failed. The operation couldn’t be completed. (RevenueCat.BackendError error 0.)
Underlying error: The receipt is not valid. The purchased product was missing in the receipt. This is typically due to a bug in StoreKit.
ERROR: 😿‼️ The receipt is not valid. The purchased product was missing in the receipt. This is typically due to a bug in StoreKit.
WARNING: sendOnFocusCallWithParams unattributed failed, will retry on next open

Purchase delegate -> No subscription....

  1. Steps to reproduce, with a description of expected vs. actual behavior

  2. Other information (e.g. stacktraces, related issues, suggestions how to fix, links for us to have context, eg. stackoverflow, etc.)

  3. Additional context
    Add any other context about the problem here.
@RCGitBot
Copy link
Contributor

RCGitBot commented Jul 4, 2024

👀 We've just linked this issue to our internal tracker and notified the team. Thank you for reporting, we're checking this out!

@aboedo aboedo self-assigned this Jul 4, 2024
@aboedo
Copy link
Member

aboedo commented Jul 4, 2024

Hey @jesus-mg-ios, off the top of my head I imagine what might be happening is that you have the time rate for accelerated subscriptions set to a very fast value (like a renewal every 2 seconds), and that it being set to that fast a renewal rate just means that we get throttled by Apple APIs and can't get a new receipt in time, leading to the issues.

This is based off of the fact that you also have a lot of transactions getting finished at the same time in the logs.

image

Setting that to a lower value, like a renewal every 5 mins, you shouldn't be able to reproduce. And in production, that should never happen, of course, since renewals take days / weeks / months / years instead of seconds. Even in TestFlight / regular Sandbox they last a few mins.

Let me know if that's not the case!

@jesus-mg-ios
Copy link
Author

jesus-mg-ios commented Jul 4, 2024 •
edited
Loading

image

Also I'm not using the storekit file on the scheme, so anyways it shoudn't doesnt care about this option.

@aboedo
Copy link
Member

aboedo commented Jul 5, 2024

@jesus-mg-ios ohh interesting, thanks for getting back to me. In that case I think it might have more to do with the amount of transactions in your sandbox account, seems like there's a lot to process right off the bat and sandbox can misbehave.

Does this happen to you if you use a different sandbox account?

@jesus-mg-ios
Copy link
Author

jesus-mg-ios commented Jul 10, 2024 •
edited
Loading

I've cleared the user's data, and after making 4-5 purchases, the issue appears (which could happen in production). It might be worth examining the code that manages transactions.

It seems related to an inconsistent internal cache, state or data race, because it’s unlikely that RevenueCat would initially indicate a purchase without showing the Apple purchase sheet, only to correct itself 2-3 seconds later. @aboedo

@XericDesign
Copy link

What app or test software is that where it shows the renewal rate options?

@jesus-mg-ios
Copy link
Author

@XericDesign you can find it in Xcode or in Sandbox user section "appstoreconnect.com "

@jesus-mg-ios
Copy link
Author

@aboedo are there any updates on it?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@aboedo aboedo

Labels
bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@aboedo @XericDesign @RCGitBot @jesus-mg-ios