Search code examples
androidin-app-billingplay-billing-library

Google in-app billing, a toast breaks everything


I don't even know what title this question should have.

So, I am working on a library to make Google-Billing as easy as possible to integrate.

Everything started after I've upgraded the library to Google's Billing v4 which replaces Purchase#getSku with Purchase#getSkus().

This is the before and after migration to billing v4:

Before (v3 library):

private void processPurchases(List<Purchase> allPurchases, boolean purchasedProductsFetched) {
        if (!allPurchases.isEmpty()) {

            List<PurchaseInfo> signatureValidPurchases = new ArrayList<>();

            //create a list with signature valid purchases
            List<Purchase> validPurchases = allPurchases.stream().filter(this::isPurchaseSignatureValid).collect(Collectors.toList());
            for (Purchase purchase : validPurchases) {

                Optional<SkuInfo> skuInfo = fetchedSkuInfoList.stream().filter(it -> it.getSkuId().equals(purchase.getSku())).findFirst();
                if (skuInfo.isPresent()) {
                    SkuDetails skuDetails = skuInfo.get().getSkuDetails();

                    PurchaseInfo purchaseInfo = new PurchaseInfo(generateSkuInfo(skuDetails), purchase);
                    signatureValidPurchases.add(purchaseInfo);

                }
            }

            if (purchasedProductsFetched) {
                fetchedPurchasedProducts = true;
                billingEventListener.onPurchasedProductsFetched(signatureValidPurchases);
            } else {
                billingEventListener.onProductsPurchased(signatureValidPurchases);
            }

            purchasedProductsList.addAll(signatureValidPurchases);

            for (PurchaseInfo purchaseInfo : signatureValidPurchases) {
                consume(purchaseInfo);

                if (shouldAutoAcknowledge) {
                    boolean wasConsumedBefore = purchaseInfo.getSkuProductType() == SkuProductType.CONSUMABLE;
                    if (!wasConsumedBefore) {
                        acknowledgePurchase(purchaseInfo);
                    }
                }
            }
        }
    }

After (v4 library):

private void processPurchases(List<Purchase> allPurchases, boolean purchasedProductsFetched) {
        if (!allPurchases.isEmpty()) {

            List<PurchaseInfo> signatureValidPurchases = new ArrayList<>();

            //create a list with signature valid purchases
            List<Purchase> validPurchases = allPurchases.stream().filter(this::isPurchaseSignatureValid).collect(Collectors.toList());
            for (Purchase purchase : validPurchases) {

                //query all SKUs as a list
                List<String> purchasesSkus = purchase.getSkus();

                //loop through all SKUs and progress for each SKU individually
                for (int i = 0; i < purchasesSkus.size(); i++) {
                    String purchasesSku = purchasesSkus.get(i);

                    Optional<SkuInfo> skuInfo = fetchedSkuInfoList.stream().filter(it -> it.getSkuId().equals(purchasesSku)).findFirst();
                    if (skuInfo.isPresent()) {
                        SkuDetails skuDetails = skuInfo.get().getSkuDetails();

                        PurchaseInfo purchaseInfo = new PurchaseInfo(generateSkuInfo(skuDetails), purchase);
                        signatureValidPurchases.add(purchaseInfo);

                    }
                }
            }

            if (purchasedProductsFetched) {
                fetchedPurchasedProducts = true;
                billingEventListener.onPurchasedProductsFetched(signatureValidPurchases);
            } else {
                billingEventListener.onProductsPurchased(signatureValidPurchases);
            }

            purchasedProductsList.addAll(signatureValidPurchases);

            for (PurchaseInfo purchaseInfo : signatureValidPurchases) {
                consume(purchaseInfo);

                if (shouldAutoAcknowledge) {
                    boolean wasConsumedBefore = purchaseInfo.getSkuProductType() == SkuProductType.CONSUMABLE;
                    if (!wasConsumedBefore) {
                        acknowledgePurchase(purchaseInfo);
                    }
                }
            }
        }
    }

Notice how getSku() and getSkus() changed.

So far so good. Moving on to the problem...

In my library, I have a listener called onProductsFetched which will provide a List<SkuInfo> with fetched SKU details.

Example:

billingConnector.setBillingEventListener(new BillingEventListener() {
            @Override
            public void onProductsFetched(@NonNull List<SkuInfo> skuDetailsList) {
                String sku;
                for (SkuInfo skuInfo : skuDetailsList) {
                    sku = skuInfo.getSkuId();

                    if (sku.equalsIgnoreCase(getString(R.string.billing_test_purchase))) {
                        Log.d("IapConnector", "SKU FOUND: " + sku);

                        Toast.makeText(SettingsActivity.this, "Fetched: " + sku, Toast.LENGTH_SHORT).show();
                    }
                }
            }
        });

Explaining the problem:

When using the code presented above in Before (v3 library) everything works as expected, the listener is triggered and the toast is shown. After switching to After (v4 library) the toast, breaks everything. The log is registered in the logcat but the toast doesn't show. Even more, if I call another log after the toast it doesn't get registered either, in fact nothing will be called after the toast, not even finish(). But wait, there's more, if I don't call the toast at all everything works well. If I replace the toast with a snackbar, the snackbar will show.

What can cause this problem? Any ideas?

Update:

If I call the Toast with delay, everything works as expected.

final Handler handler = new Handler(Looper.getMainLooper());
                        String finalSku = sku;
                        handler.postDelayed(new Runnable() {
                            @Override
                            public void run() {
                                Toast.makeText(SettingsActivity.this, "Fetched: " + finalSku, Toast.LENGTH_SHORT).show();
                            }
                        }, 100);

Update2:

Logcat. Notice D/IapConnector: SKU FOUND: test_purchase7 is called which is the log before the Toast

2021-06-07 11:11:37.633 31680-31680/games.moisoni.evfp I/ViewRootImpl@ef10be4[MainActivity]: ViewPostIme pointer 0
2021-06-07 11:11:37.710 31680-31680/games.moisoni.evfp I/ViewRootImpl@ef10be4[MainActivity]: ViewPostIme pointer 1
2021-06-07 11:11:37.747 31680-32423/games.moisoni.evfp V/FA: Recording user engagement, ms: 11555
2021-06-07 11:11:37.752 31680-32423/games.moisoni.evfp V/FA: Connecting to remote service
2021-06-07 11:11:37.755 31680-32423/games.moisoni.evfp V/FA: Activity paused, time: 53257103
2021-06-07 11:11:37.769 31680-32423/games.moisoni.evfp V/FA: Connection attempt already in progress
2021-06-07 11:11:37.770 31680-32417/games.moisoni.evfp V/FA: onActivityCreated
2021-06-07 11:11:37.772 31680-31680/games.moisoni.evfp I/DecorView: [INFO] isPopOver=false, config=true
2021-06-07 11:11:37.772 31680-31680/games.moisoni.evfp I/DecorView: updateCaptionType >> DecorView@25a7196[], isFloating=false, isApplication=true, hasWindowDecorCaption=false, hasWindowControllerCallback=true
2021-06-07 11:11:37.772 31680-31680/games.moisoni.evfp D/DecorView: setCaptionType = 0, this = DecorView@25a7196[]
2021-06-07 11:11:37.782 31680-31680/games.moisoni.evfp D/ScrollView: initGoToTop
2021-06-07 11:11:37.830 31680-31680/games.moisoni.evfp D/IapConnector: Billing service: connecting...
2021-06-07 11:11:37.853 31680-32423/games.moisoni.evfp V/FA: Activity resumed, time: 53257213
2021-06-07 11:11:37.857 31680-31680/games.moisoni.evfp D/InputTransport: Input channel constructed: 'f0be3be', fd=218
2021-06-07 11:11:37.859 31680-31680/games.moisoni.evfp I/ViewRootImpl@d0eac04[SettingsActivity]: setView = com.android.internal.policy.DecorView@25a7196 TM=true
2021-06-07 11:11:37.870 31680-32423/games.moisoni.evfp V/FA: Connection attempt already in progress
2021-06-07 11:11:37.872 31680-32423/games.moisoni.evfp V/FA: Connection attempt already in progress
2021-06-07 11:11:37.879 31680-31680/games.moisoni.evfp D/ViewRootImpl@d0eac04[SettingsActivity]: controlInsetsForCompatibility: hideByFlags=0x3, showByFlags=0x0, flags=0x89810500, sysUiVis=0x1706, matchParent=true, nonAttachedAppWindow=true
2021-06-07 11:11:37.879 31680-31680/games.moisoni.evfp D/InsetsSourceConsumer: setRequestedVisible: visible=false, type=1, host=games.moisoni.evfp/games.moisoni.evfp.SettingsActivity, from=android.view.InsetsSourceConsumer.hide:236 android.view.InsetsController.collectSourceControls:1172 android.view.InsetsController.controlAnimationUnchecked:1049 android.view.InsetsController.applyAnimation:1417 android.view.InsetsController.hide:984 android.view.InsetsController.hide:967 android.view.ViewRootImpl.controlInsetsForCompatibility:2852 android.view.ViewRootImpl.performTraversals:3314 android.view.ViewRootImpl.doTraversal:2618 android.view.ViewRootImpl$TraversalRunnable.run:9965 
2021-06-07 11:11:37.879 31680-31680/games.moisoni.evfp D/InsetsSourceConsumer: setRequestedVisible: visible=false, type=0, host=games.moisoni.evfp/games.moisoni.evfp.SettingsActivity, from=android.view.InsetsSourceConsumer.hide:236 android.view.InsetsController.collectSourceControls:1172 android.view.InsetsController.controlAnimationUnchecked:1049 android.view.InsetsController.applyAnimation:1417 android.view.InsetsController.hide:984 android.view.InsetsController.hide:967 android.view.ViewRootImpl.controlInsetsForCompatibility:2852 android.view.ViewRootImpl.performTraversals:3314 android.view.ViewRootImpl.doTraversal:2618 android.view.ViewRootImpl$TraversalRunnable.run:9965 
2021-06-07 11:11:37.893 31680-31680/games.moisoni.evfp I/SurfaceControl: assignNativeObject: nativeObject = 0 Surface(name=null)/@0xa900b0f / android.view.SurfaceControl.readFromParcel:1115 android.view.IWindowSession$Stub$Proxy.relayout:1820 android.view.ViewRootImpl.relayoutWindow:9005 android.view.ViewRootImpl.performTraversals:3360 android.view.ViewRootImpl.doTraversal:2618 android.view.ViewRootImpl$TraversalRunnable.run:9965 android.view.Choreographer$CallbackRecord.run:1010 android.view.Choreographer.doCallbacks:809 android.view.Choreographer.doFrame:744 android.view.Choreographer$FrameDisplayEventReceiver.run:995 
2021-06-07 11:11:37.894 31680-31680/games.moisoni.evfp I/ViewRootImpl@d0eac04[SettingsActivity]: Relayout returned: old=(0,0,1440,3040) new=(0,144,1440,3040) req=(1440,3040)0 dur=10 res=0x7 s={true 535365349344} ch=true fn=-1
2021-06-07 11:11:37.902 31680-31680/games.moisoni.evfp D/ScrollView:  onsize change changed 
2021-06-07 11:11:37.902 31680-31680/games.moisoni.evfp I/ViewRootImpl@d0eac04[SettingsActivity]: [DP] dp(1) 1 android.view.ViewRootImpl.reportNextDraw:10951 android.view.ViewRootImpl.performTraversals:3845 android.view.ViewRootImpl.doTraversal:2618 
2021-06-07 11:11:37.902 31680-31680/games.moisoni.evfp I/ViewRootImpl@d0eac04[SettingsActivity]: [DP] pd() Asnyc report
2021-06-07 11:11:37.922 31680-31680/games.moisoni.evfp I/ViewRootImpl@d0eac04[SettingsActivity]: [DP] pdf(0) 1 android.view.ViewRootImpl.lambda$performDraw$1$ViewRootImpl:4668 android.view.-$$Lambda$ViewRootImpl$DJd0VUYJgsebcnSohO6h8zc_ONI.run:6 android.os.Handler.handleCallback:938 
2021-06-07 11:11:37.922 31680-31680/games.moisoni.evfp I/ViewRootImpl@d0eac04[SettingsActivity]: [DP] rdf()
2021-06-07 11:11:37.927 31680-31680/games.moisoni.evfp I/ViewRootImpl@ef10be4[MainActivity]: MSG_WINDOW_FOCUS_CHANGED 0 1
2021-06-07 11:11:37.928 31680-32758/games.moisoni.evfp D/IapConnector: Billing service: connected
2021-06-07 11:11:37.933 31680-32423/games.moisoni.evfp D/FA: Connected to remote service
2021-06-07 11:11:37.935 31680-32423/games.moisoni.evfp V/FA: Processing queued up service tasks: 4
2021-06-07 11:11:37.938 31680-32759/games.moisoni.evfp D/IapConnector: Query SKU Details: data found
2021-06-07 11:11:37.938 31680-32758/games.moisoni.evfp D/IapConnector: Subscriptions support check: success
2021-06-07 11:11:37.939 31680-32759/games.moisoni.evfp D/IapConnector: SKU FOUND: test_purchase7
2021-06-07 11:11:37.940 31680-32759/games.moisoni.evfp D/CompatibilityChangeReporter: Compat change id reported: 147798919; UID 10745; state: ENABLED
2021-06-07 11:11:37.948 31680-31680/games.moisoni.evfp D/SurfaceControl: hide : mNativeObject = 531070505712 - sc.mNativeObject = 530532840928 - Surface(name=Surface(name=a8e3812 NavigationBar0)/@0x38b32cd - animation-leash)/@0x2a3e45d
2021-06-07 11:11:37.948 31680-31680/games.moisoni.evfp D/SurfaceControl: nativeSetFlags Done : Surface(name=Surface(name=a8e3812 NavigationBar0)/@0x38b32cd - animation-leash)/@0x2a3e45d
2021-06-07 11:11:37.949 31680-31680/games.moisoni.evfp D/SurfaceControl: hide : mNativeObject = 531070497088 - sc.mNativeObject = 530532838464 - Surface(name=Surface(name=e511e35 StatusBar)/@0xbf071b - animation-leash)/@0xc4ac1d2
2021-06-07 11:11:37.949 31680-31680/games.moisoni.evfp D/SurfaceControl: nativeSetFlags Done : Surface(name=Surface(name=e511e35 StatusBar)/@0xbf071b - animation-leash)/@0xc4ac1d2
2021-06-07 11:11:37.951 31680-31680/games.moisoni.evfp I/SurfaceControl: release : mNativeObject = 530532781344 - Surface(name=Surface(name=37630c6 InputMethod)/@0xd11e623 - animation-leash)/@0xe000b05 / android.view.-$$Lambda$Rl1VZmNJ0VZDLK0BAbaVGis0rrA.accept:2 android.view.InsetsSourceControl.release:170 android.view.InsetsSourceConsumer.setControl:202 android.view.ImeInsetsSourceConsumer.setControl:154 
2021-06-07 11:11:37.951 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject s[530532781344]
2021-06-07 11:11:37.951 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject e[530532781344]
2021-06-07 11:11:37.951 31680-31680/games.moisoni.evfp I/SurfaceControl: release : mNativeObject = 530532786048 - Surface(name=Surface(name=a8e3812 NavigationBar0)/@0x38b32cd - animation-leash)/@0xd4eb2a3 / android.view.-$$Lambda$Rl1VZmNJ0VZDLK0BAbaVGis0rrA.accept:2 android.view.InsetsSourceControl.release:170 android.view.InsetsSourceConsumer.setControl:202 android.view.InsetsController.onControlsChanged:833 
2021-06-07 11:11:37.951 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject s[530532786048]
2021-06-07 11:11:37.951 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject e[530532786048]
2021-06-07 11:11:37.951 31680-31680/games.moisoni.evfp I/SurfaceControl: release : mNativeObject = 530532732064 - Surface(name=Surface(name=e511e35 StatusBar)/@0xbf071b - animation-leash)/@0x201e9a0 / android.view.-$$Lambda$Rl1VZmNJ0VZDLK0BAbaVGis0rrA.accept:2 android.view.InsetsSourceControl.release:170 android.view.InsetsSourceConsumer.setControl:202 android.view.InsetsController.onControlsChanged:833 
2021-06-07 11:11:37.951 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject s[530532732064]
2021-06-07 11:11:37.951 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject e[530532732064]
2021-06-07 11:11:37.955 31680-31680/games.moisoni.evfp I/ViewRootImpl@d0eac04[SettingsActivity]: MSG_WINDOW_FOCUS_CHANGED 1 1
2021-06-07 11:11:37.955 31680-31680/games.moisoni.evfp D/InputMethodManager: prepareNavigationBarInfo() DecorView@25a7196[SettingsActivity]
2021-06-07 11:11:37.955 31680-31680/games.moisoni.evfp D/InputMethodManager: getNavigationBarColor() -16711423
2021-06-07 11:11:37.957 31680-31680/games.moisoni.evfp D/InputMethodManager: prepareNavigationBarInfo() DecorView@25a7196[SettingsActivity]
2021-06-07 11:11:37.957 31680-31680/games.moisoni.evfp D/InputMethodManager: getNavigationBarColor() -16711423
2021-06-07 11:11:37.957 31680-31680/games.moisoni.evfp V/InputMethodManager: Starting input: tba=games.moisoni.evfp ic=null mNaviBarColor -16711423 mIsGetNaviBarColorSuccess true , NavVisible : false , NavTrans : false
2021-06-07 11:11:37.957 31680-31680/games.moisoni.evfp D/InputMethodManager: startInputInner - Id : 0
2021-06-07 11:11:37.957 31680-31680/games.moisoni.evfp I/InputMethodManager: startInputInner - mService.startInputOrWindowGainedFocus
2021-06-07 11:11:37.959 31680-31680/games.moisoni.evfp D/InputTransport: Input channel constructed: 'ClientS', fd=221
2021-06-07 11:11:37.959 31680-31680/games.moisoni.evfp D/InputTransport: Input channel destroyed: 'ClientS', fd=111
2021-06-07 11:11:37.998 31680-31680/games.moisoni.evfp I/SurfaceControl: release : mNativeObject = 530532838240 - Surface(name=Surface(name=37630c6 InputMethod)/@0xd11e623 - animation-leash)/@0x46f291e / android.view.-$$Lambda$Rl1VZmNJ0VZDLK0BAbaVGis0rrA.accept:2 android.view.InsetsSourceControl.release:170 android.view.InsetsSourceConsumer.setControl:202 android.view.ImeInsetsSourceConsumer.setControl:154 
2021-06-07 11:11:37.998 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject s[530532838240]
2021-06-07 11:11:37.998 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject e[530532838240]
2021-06-07 11:11:37.999 31680-31680/games.moisoni.evfp D/SurfaceControl: hide : mNativeObject = 531069881968 - sc.mNativeObject = 530532839920 - Surface(name=Surface(name=37630c6 InputMethod)/@0xd11e623 - animation-leash)/@0xd0fd5ff
2021-06-07 11:11:37.999 31680-31680/games.moisoni.evfp D/SurfaceControl: nativeSetFlags Done : Surface(name=Surface(name=37630c6 InputMethod)/@0xd11e623 - animation-leash)/@0xd0fd5ff
2021-06-07 11:11:38.001 31680-31680/games.moisoni.evfp I/SurfaceControl: release : mNativeObject = 530532840928 - Surface(name=Surface(name=a8e3812 NavigationBar0)/@0x38b32cd - animation-leash)/@0x2a3e45d / android.view.-$$Lambda$Rl1VZmNJ0VZDLK0BAbaVGis0rrA.accept:2 android.view.InsetsSourceControl.release:170 android.view.InsetsSourceConsumer.setControl:202 android.view.InsetsController.onControlsChanged:833 
2021-06-07 11:11:38.001 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject s[530532840928]
2021-06-07 11:11:38.001 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject e[530532840928]
2021-06-07 11:11:38.001 31680-31680/games.moisoni.evfp I/SurfaceControl: release : mNativeObject = 530532838464 - Surface(name=Surface(name=e511e35 StatusBar)/@0xbf071b - animation-leash)/@0xc4ac1d2 / android.view.-$$Lambda$Rl1VZmNJ0VZDLK0BAbaVGis0rrA.accept:2 android.view.InsetsSourceControl.release:170 android.view.InsetsSourceConsumer.setControl:202 android.view.InsetsController.onControlsChanged:833 
2021-06-07 11:11:38.001 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject s[530532838464]
2021-06-07 11:11:38.001 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject e[530532838464]
2021-06-07 11:11:38.185 31680-31680/games.moisoni.evfp I/ViewRootImpl@ef10be4[MainActivity]: stopped(true) old=false
2021-06-07 11:11:38.187 31680-31680/games.moisoni.evfp I/SurfaceControl: release : mNativeObject = 530532758608 - Surface(name=games.moisoni.evfp/games.moisoni.evfp.MainActivity$_31680)/@0xf744215 / android.view.ViewRootImpl.destroySurface:2484 android.view.ViewRootImpl.setWindowStopped:2332 android.view.WindowManagerGlobal.setStoppedState:741 android.app.Activity.performStop:8423 
2021-06-07 11:11:38.187 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject s[530532758608]
2021-06-07 11:11:38.187 31680-31680/games.moisoni.evfp I/SurfaceControl: nativeRelease nativeObject e[530532758608]
2021-06-07 11:11:38.202 31680-32437/games.moisoni.evfp W/libEGL: EGLNativeWindowType 0x7ca63be2a0 disconnect failed
2021-06-07 11:11:38.206 31680-31680/games.moisoni.evfp I/SurfaceControl: assignNativeObject: nativeObject = 0 Surface(name=null)/@0xf744215 / android.view.SurfaceControl.readFromParcel:1115 android.view.IWindowSession$Stub$Proxy.relayout:1810 android.view.ViewRootImpl.relayoutWindow:9005 android.view.ViewRootImpl.performTraversals:3360 android.view.ViewRootImpl.doTraversal:2618 android.view.ViewRootImpl$TraversalRunnable.run:9965 android.view.Choreographer$CallbackRecord.run:1010 android.view.Choreographer.doCallbacks:809 android.view.Choreographer.doFrame:744 android.view.Choreographer$FrameDisplayEventReceiver.run:995 
2021-06-07 11:11:38.206 31680-31680/games.moisoni.evfp I/SurfaceControl: assignNativeObject: nativeObject = 0 Surface(name=null)/@0xda8bd8d / android.view.SurfaceControl.readFromParcel:1115 android.view.IWindowSession$Stub$Proxy.relayout:1820 android.view.ViewRootImpl.relayoutWindow:9005 android.view.ViewRootImpl.performTraversals:3360 android.view.ViewRootImpl.doTraversal:2618 android.view.ViewRootImpl$TraversalRunnable.run:9965 android.view.Choreographer$CallbackRecord.run:1010 android.view.Choreographer.doCallbacks:809 android.view.Choreographer.doFrame:744 android.view.Choreographer$FrameDisplayEventReceiver.run:995 
2021-06-07 11:11:38.207 31680-31680/games.moisoni.evfp I/ViewRootImpl@ef10be4[MainActivity]: Relayout returned: old=(0,144,1440,3040) new=(0,144,1440,3040) req=(1440,2896)8 dur=4 res=0x5 s={false 0} ch=false fn=-1

Solution

  • In V4.0 BillingClient method callbacks call in background thread, not in Main thread.

    Workaround is to change thread to Main in BillingClient callbacks.

    Call you method processPurchases() with Toast in UI thread.