RevenueCat / react-native-purchases

React Native in-app purchases and subscriptions made easy. Support for iOS and Android.
https://www.revenuecat.com
MIT License
767 stars 84 forks source link

Calling purchasePackage calls the correct code in Android, but the listener callback fails to fire in React Native #354

Closed Rob117 closed 2 years ago

Rob117 commented 2 years ago

Describe the bug

On Android only (iOS works flawlessly), purchases seem to work, but the awaited method Purchases.purchasePackage never returns or throws an error.

See code, below:

 try {
    console.log('Purchasing package: ', packageToPurchase.identifier);
    const res = await Purchases.purchasePackage(packageToPurchase);
    console.log('purchase completed');
    console.log(JSON.stringify(res));
  } catch (e){
    console.error('Purchasing package failed', e);
   }

In this example, "Purchasing package: $rc_monthly" is printed to the metro debug logs console.

However, "Purchase completed" and "Purchasing package failed" are never called, even though using adb logcat shows debug logs that suggest that the methods are correctly being called under the hood.

Furthermore, on a successful purchase, my webhooks that grant access to users are successfully being called with purchase information. The Google Play Store also confirms the purchase, and it shows in the sandbox panel on RC.

This leads me to believe that the purchase information is going through, but there is some kind of disconnect between the android layer callback and the React Native callback code.

If it helps, I once had expo-in-app-purchases installed, but I removed the package from package.json, deleted the build folder, ran ./android/gradlew clean for good measure, and then built the app. I still have the above issue.

  1. Environment
    1. Platform: Android
    2. SDK version: 4.6.0
    3. OS version: macOS 12.4 (arm64 M1 Pro)
    4. Xcode/Android Studio version: (Android Studio) 2021.1 AI-211.7628.21.2111.8309675
    5. React Native version: 0.66.3
    6. SDK installation (CocoaPods + version or manual): yarn && react-native link
    7. How widespread is the issue. Percentage of devices affected: 100%
  2. Debug logs that reproduce the issue
    • On successful purchase:
      06-21 15:38:58.117 15688 20680 D [Purchases] - DEBUG: ℹ️ API request started: POST /receipts
      06-21 15:38:58.119 15688 20680 D [Purchases] - DEBUG: ℹ️ API request completed with status: POST /receipts 200
      06-21 15:38:58.124 15688 20680 D [Purchases] - DEBUG: 💰 Acknowledging purchase with token TOKEN_HERE
      06-21 15:38:58.125 15688 20680 D [Purchases] - DEBUG: ℹ️ PurchaserInfo updated, sending to listener.
      06-21 15:38:58.128  7630 10001 I Finsky  : [487] gch.a(16): io.kichi.kichi: Account from first account - [CHARS_HERE]
      06-21 15:38:58.128  7630 10001 I Finsky  : [487] gch.a(63): Billing preferred account via installer for io.kichi.kichi: [CHARS_HERE]
      06-21 15:38:58.921  7630  7630 I Finsky  : [2] frt.a(161): Applying library update: account=[CHARS_HERE]
      06-21 15:38:58.928  7630  7630 I Finsky  : [2] gpa.a(3): [ContentSync] App library has changed, requesting content sync.
      06-21 15:38:58.931  7630 20341 I Finsky  : [800] zz.YD(48): [ContentSync] finished, scheduled=false
      06-21 15:38:58.932 15688 20711 D [Purchases] - DEBUG: ℹ️ Saving token TOKEN_HERE with hash HASH_HERE
      06-21 15:38:58.932 15688 20711 D [Purchases] - DEBUG: ℹ️ Tokens already posted: []
      06-21 15:38:58.932 15688 20711 D [Purchases] - DEBUG: ℹ️ Tokens in cache before saving []
      06-21 15:38:58.932 15688 20711 D [Purchases] - DEBUG: ℹ️ Saving tokens [TOKEN_HERE]

On error purchase:

06-21 15:33:35.238 15688 15688 W ProxyBillingActivity: Activity finished with resultCode 0 and billing's responseCode: 7
06-21 15:33:35.240  7630 18492 W FA      : Failed to retrieve Firebase Instance Id
06-21 15:33:35.271 15688 15688 W BillingHelper: Couldn't find purchase lists, trying to find single data.
06-21 15:33:35.271 15688 15688 W BillingHelper: Received a bad purchase data.
06-21 15:33:35.271 15688 15688 W BillingHelper: Couldn't find single purchase data as well.
06-21 15:33:35.271 15688 15688 E [Purchases] - ERROR: 🤖‼️ BillingWrapper purchases failed to update: DebugMessage: . ErrorCode: ITEM_ALREADY_OWNED.null
06-21 15:33:35.271 15688 15688 E [Purchases] - ERROR: 🤖‼️ This product is already active for the user.
06-21 15:33:35.273  2556  2613 E FrameEvents: updateAcquireFence: Did not find frame.
06-21 15:33:35.273  7630  9687 D OpenGLRenderer: endAllActiveAnimators on 0xb4000071817aab10 (RippleDrawable) with handle 0xb4000070917955f0
06-21 15:33:35.276  1891  4319 W AutofillManagerServiceImpl: getFillEventHistory() called by UID 10148, but service UID is 10362
06-21 15:33:35.296  2556  2590 D Bubbs.StackCtrl: Setting position to (-8.000000, 1155.000000).
06-21 15:33:35.296  1891  2710 W ServiceManager: Permission failure: android.permission.HIGH_SAMPLING_RATE_SENSORS from uid=10601 pid=15688
06-21 15:33:35.296  1891  2710 W ServiceManager: Permission failure: android.permission.HIGH_SAMPLING_RATE_SENSORS from uid=10601 pid=15688
06-21 15:33:35.297  1172  1172 I sensors-hal: [hal]flush_physical_sensor:355, android.sensor.accelerometer/11
06-21 15:33:35.297  1172  1172 I sensors-hal: [hal]flush_physical_sensor:361, android.sensor.accelerometer/11 completed
06-21 15:33:35.298  1172 18107 I sensors-hal: [ssc_sensor]ssc_conn_resp_cb:686, resp_value = 0
06-21 15:33:35.298  7630  7630 W ProxyAndroidLoggerBackend: Too many Flogger logs received before configuration. Dropping old logs.
06-21 15:33:35.309 15688 15956 D [Purchases] - DEBUG: ℹ️ Debug logging enabled
06-21 15:33:35.309 15688 15956 D [Purchases] - DEBUG: ℹ️ SDK Version - 4.6.1
06-21 15:33:35.309 15688 15956 D [Purchases] - DEBUG: 👤 Initial App User ID - null
06-21 15:33:35.309 15688 15956 D [Purchases] - DEBUG: 👤 Identifying App User ID: LGwBzj4X8tTWHE792MfRHehEAnf2
06-21 15:33:35.310 15688 15956 D [Purchases] - DEBUG: ℹ️ Deleting old synced subscriber attributes that don't belong to LGwBzj4X8tTWHE792MfRHehEAnf2
06-21 15:33:35.310 15688 15956 D [Purchases] - DEBUG: ℹ️ Listener set
06-21 15:33:35.311 15688 15956 D [Purchases] - DEBUG: ℹ️ Sending latest PurchaserInfo to listener.
  1. Steps to reproduce, with a description of expected vs. actual behavior

I'm genuinely not sure what the error might be from looking at the logs, so I'm not sure how to reproduce this. Any new information would be deeply welcome at this point.

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

If there is no way to get client-side purchases working with RC, could I figure out a way to use expo-in-app-purchases + RC observer mode to send the receipts to RC and have them grant entitlements anyway? The RC server-side code is so much simpler and I'd really like to not have to roll back billing right now.

Additional context

I searched the forums and saw that having certain audio plugins might cause an issue and require calling Purchases.Setup just before making a purchase. I tried to change my app structure to mimic that flow, but it made no difference (I call Purchase.setup in App.tsx as recommended by the docs.

If there is anything else I can provide to help troubleshoot, please let me know

aboedo commented 2 years ago

Hey @Rob117, thanks for reporting!! I haven't been able to reproduce it 😕 Does this reproduce for you on our example apps?

You can try this by:

This will help us isolate whether there's something left over in the current configuration that might be causing the issues, so we can figure out next steps

Rob117 commented 2 years ago

So! Here's what debugging with the example app got me on a Pixel 5.

important: To replicate my setup, I downgraded to react-native 0.66.3.

1) The first call succeeds, no problem. 2) The second call which would trigger an error because the account already owned that purchase fired the error modal, but only intermittedly.

I'll try to put some debug logs in the native android code for my app + register a purchase listener and see what happens next.

Rob117 commented 2 years ago

Update - it might actually be something interfering on the react native side because I'm not seeing anything on Apple after resetting my sandbox account - which is interesting. Will investigate.

aboedo commented 2 years ago

@Rob117 Thanks for reporting back!

A couple of things to keep in mind:

Rob117 commented 2 years ago

Okay, so I got it working consistently on Apple.

It turns out that in the example Magic Weather repo, the Podfile.lock shows

- RNPurchases (4.5.2):
    - PurchasesHybridCommon (= 2.0.1)
    - React-Core

This is a problem, because installing the latest version (4.6.0) actually installed - RNPurchases (4.6.0) in my project, which did not work for me. Downgrading my yarn package by specifying 4.5.2 to match the settings from the example project made Apple much more consistent.

I still can't get Android to work, but after downgrading my pods the Apple side is no longer an issue, so I'm wondering if maybe running react-native-link and linking to 4.6.0 in Android messed something up (unlikely as looking at the code it's just linked against the current node modules).

Update: I just checked the Android code in the repo and it's 4.6.0, so not sure :(

aboedo commented 2 years ago

@Rob117 thanks for calling out the issue with the Podfile.lock. I'm going to remove it from version control so it doesn't cause issues in the future.

Happy to help with the Android issue! What error are you getting?

aboedo commented 2 years ago

BTW, for the Podfile.lock, you should be able to just delete the file locally and retry (you may have to manually go to the ios folder and run pod install)

Rob117 commented 2 years ago

So for my Android, the problem is that if I set up a dedicated purchase listener(addPurchaserInfoUpdateListener), it will correctly fire off after a purchase has been made. This tells me that post-purchase information is making it across the native-to-react bridge with no problem, but only for the listener.

(Quick aside - is it supposed to fire off a bunch of times after a purchase? It fires off between 2-5 times for me).

Using the Purchases.purchasePackage method involves an async-await statement that isn't closing out on the react-native side.

To reiterate - addPurchaserInfoUpdateListener -> events fire off from native into RN, received on RN no problem. Same for all the methods that get packages, etc.

purchasePackage or purchaseProduct -> Native methods fire off, purchase is successfully processed / rejected as expected, but the callback never resolves on the native side to pass the result back to RN.

If you have any Android files that I could start debugging from (for example, where I should put breakpoints or debug logs right before the callback should be resolved on native side) that would be awesome.

Rob117 commented 2 years ago

Alright, this might be the last update because I've gotten about as far as I can before trying to link the uncompiled Common binaries from the repo.

I added the following logs in RNPurchasesModule.java

 @NotNull
    private OnResult getOnResult(final Promise promise) {
        Log.e("RNPurchases", "RESULT GOTTEN");
        return new OnResult() {
            @Override
            public void onReceived(Map<String, ?> map) {
                Log.e("RNPurchases", "On received called");
                promise.resolve(convertMapToWriteableMap(map));
            }

            @Override
            public void onError(ErrorContainer errorContainer) {
                Log.e("RNPurchases", "On error called");
                promise.reject(errorContainer.getCode() + "", errorContainer.getMessage(),
                        convertMapToWriteableMap(errorContainer.getInfo()));
            }
        };
    }

Checking adb logcat, I find that RESULT GOTTEN fires off as expected, but On received called does not fire off after a purchase has succeeded (and the error log does not fire off after failure). I'm running out of things to try, so if you have anything else I could look at I'd really appreciate it.

aboedo commented 2 years ago

@Rob117 so to clarify, with the MagicWeather app, the callbacks seem to be working fine on Android but not on your app, right? 🤔

I'm honestly kinda stumped, I'm going to ask the team if they've ever experienced anything like this.

In the meantime, I'd suggest upgrading to the latest RN version, it looks like there are a number of fixes related to promises, there's a chance that it might help

aboedo commented 2 years ago

It's likely that another plugin is interfering with the call.

We had an issue a while back in our Flutter where another plugin was calling onDetachedFromEngine from Google's Billing Client, and we were disconnecting from it when it's called.

This might be something similar. We should try to figure out which plugin is causing the compatibility issues. Could you tell us which plugins you're using? Also, if at all possible, could you try removing plugins and trying to see which one might be causing the issue with RevenueCat?

Rob117 commented 2 years ago

Thanks, I appreciate the help.

It's actually going to be quite a bit of work to upgrade RN and test plugins right now, so I've decided to use my old billing code and use RC in observer mode. That combination seems to work just fine - I get working client-side code with RC's simplified webhooks.

I'll reference this issue if I ever decide to switch to a purely RC implementation in the future.

aboedo commented 2 years ago

Sounds good. I'll close this issue in the meantime, but feel free to reopen (or open a new one) if you do decide to give the full implementation another try and need some assistance.

Also, don't hesitate to reach out if you need any help at all! Have a great day!

Rob117 commented 1 year ago

I fixed it, and I feel pretty silly.

So I decided to bite the bullet and really dig into this. I spent time using the Android debugger to step through everything, removed all other suspect plugins, looked at all my manifests and settings, etc. etc., until I looked at logcat again and noticed this gem.

07-25 09:23:47.135 24828 24916 I [Purchases] - INFO: Purchases instance already set. Did you mean to configure two Purchases objects?
07-25 09:23:47.145 24828 24916 D [Purchases] - DEBUG: ℹ️ Purchases configured with response verification: DISABLED

I turns out I spent a ton of time debugging only to realize that I was accidentally running Purchases.configure inside of my top-level app component. This meant that when the top level component re-rendered for any reason, it configured two purchase listeners and then turned off response verification. Also, for some strange reason, this only happened on Android.

Moving it outside to a config file solved all my problems.

Thank you for taking the time last year to troubleshoot this with me.

I hope that this helps anyone else with this very specific, strange problem in the future.