GooglePlay complete the purchase process, despite IAP calling OnPurchaseFailed

I sell Consumable items.
I have been using IAP(1.9.3) but some android device merely crashed when buying an item. So I decided to use the lastest IAP(1.21.0/1.20.1)

IAP(1.21.0) did not cause the error, but I met a weird bug with Android OS.

At first, push the home button just after buy an item. And then back to the app, IAP call `IStoreController.OnPurchaseFailed`. At this time, PurchaseFailureReason is "Unknown".
Despite purchase failure, Google Play has completed the purchase process.
So when retry to purchase same item after getting "Unknown", IAP call `IStoreController.OnPurchaseFailed` with "DuplicateTransaction", it will never call `IStoreController.ProcessPurchase`.
After restarting the app, IAP call `IStoreController.ProcessPurchase` for the item.

It would not cause until the players do strange operation at purchasing an item, but some players have met this bug.
I think it is weird that GooglePlay has completed the purchase process, despite IAP calling OnPurchaseFailed.

How do I deal with PurchaseFailure after Google Play completing the purchase process?
(I couldn't reproduce it with iOS so far.)

 

Are you able to reproduce? The behavior you describe would not be expected. Please provide device logs: https://forum.unity.com/threads/how-to-capturing-device-logs-on-android.528680/

 

Thank you for the reply.
Yes, I can reproduce this on my Android device( Xperia SO-03J / Android8.0 ).

As described before post,
[1] Push the home button just after buying an item.
[2] Then back to the app.
The Purchase process fails, but GooglePlay completes purchase process.

I can know GooglePlay completing the purchase because I get a mail from GooglePlay which is order details.
After that, when I restart the app and IAP call 'IStoreController.ProcessPurchase', the device log tells "Finish transaction:GPA.XXXXX". It is the same number of transaction Id of the order details.

To fail purchase process on purpose is very difficult in timing to do [1], but I can reproduce this with a high probability.

Here is the device log of processing [1] , [2] and trying to buy an item after the purchase fail.

11-02 09:22:34.471 28181 28220 I UnityIAP: isUnityVrEnabled = false

11-02 09:22:34.472 28181 28220 I UnityIAP: onPurchaseProduct: com.hoge.foo.item1

11-02 09:22:34.472 28181 28220 I UnityIAP: ITEM TYPE:inapp

11-02 09:22:34.538 28181 28181 I UnityIAP: Creating purchase activity

11-02 09:22:34.538 28181 28181 I UnityIAP: oldSkuMetadata is null

11-02 09:22:34.539 28181 28454 I UnityIAP: invoking callback

11-02 09:22:34.539 28181 28454 I UnityIAP: Constructing buy intent for com.hoge.foo.item1, item type: inapp

11-02 09:22:34.583 28181 28454 I UnityIAP: Launching buy intent for com.hoge.foo.item1. Request code: 999

11-02 09:22:40.789  1503  3709 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=com.hoge.foo/com.google.firebase.MessagingUnityPlayerActivity bnds=[36,665][288,924]} from uid 10266

11-02 09:22:40.793 28181 28181 I UnityIAP: onActivityResult

11-02 09:22:40.793 28181 28181 I UnityIAP: onIabPurchaseFinished: false

11-02 09:22:40.794 28181 28181 I UnityIAP: Null data in IAB result (response: -1002:Bad response received)

11-02 09:22:40.794 28181 28181 I UnityIAP: Purchase response code:-1002

11-02 09:22:40.795 28181 28181 I UnityIAP: Received bad response, polling for successful purchases to investigate failure more deeply

11-02 09:22:40.795 28181 28454 I UnityIAP: invoking callback

11-02 09:22:40.795 28181 28454 I UnityIAP: Querying owned items, item type: inapp

11-02 09:22:40.795 28181 28454 I UnityIAP: Package name: com.hoge.foo

11-02 09:22:40.795 28181 28454 I UnityIAP: Calling getPurchases with continuation token: null

11-02 09:22:40.798  1503  3709 E ActivityTrigger: activityResumeTrigger: not whiteListedcom.hoge.foo/com.google.firebase.MessagingUnityPlayerActivity/202

11-02 09:22:40.803  1503  3709 E ActivityTrigger: activityResumeTrigger: not whiteListedcom.hoge.foo/com.google.firebase.MessagingUnityPlayerActivity/202

11-02 09:22:40.815  1503  5557 E ActivityTrigger: activityResumeTrigger: not whiteListedcom.hoge.foo/com.google.firebase.MessagingUnityPlayerActivity/202

11-02 09:22:40.822  1503  1513 E ActivityTrigger: activityResumeTrigger: not whiteListedcom.hoge.foo/com.google.firebase.MessagingUnityPlayerActivity/202

11-02 09:22:40.825  1503  3706 E ActivityTrigger: activityResumeTrigger: not whiteListedcom.hoge.foo/com.google.firebase.MessagingUnityPlayerActivity/202

11-02 09:22:40.861 28181 28454 I UnityIAP: Owned items response: 0

11-02 09:22:40.861 28181 28454 I UnityIAP: Continuation token: null

11-02 09:22:41.035  1503  9359 I InputDispatcher: Focus entered window: Window{e76c79a u0 com.hoge.foo/com.google.firebase.MessagingUnityPlayerActivity}

11-02 09:22:41.098  1503  1554 I Timeline: Timeline: Activity_windows_visible id: ActivityRecord{27cdce1 u0 com.hoge.foo/com.google.firebase.MessagingUnityPlayerActivity t38029} time:173881989 diff:292 start:warm|cch-act batt:81|2 mw:off|1 mem:1377052|0|87|12|24 cpu:[1478400, 1478400, 1478400, 1478400]

11-02 09:23:00.999 28181 28220 I UnityIAP: isUnityVrEnabled = false

11-02 09:23:01.000 28181 28220 I UnityIAP: onPurchaseProduct: com.hoge.foo.item1

11-02 09:23:01.000 28181 28220 I UnityIAP: ITEM TYPE:inapp

11-02 09:23:01.070 28181 28181 I UnityIAP: Creating purchase activity

11-02 09:23:01.070 28181 28181 I UnityIAP: oldSkuMetadata is null

11-02 09:23:01.072 28181 28454 I UnityIAP: invoking callback

11-02 09:23:01.072 28181 28454 I UnityIAP: Constructing buy intent for com.hoge.foo.item1, item type: inapp

11-02 09:23:01.124 28181 28454 I UnityIAP: onIabPurchaseFinished: false

11-02 09:23:01.124 28181 28454 I UnityIAP: Unable to buy item (response: 7:Item Already Owned)

11-02 09:23:01.124 28181 28454 I UnityIAP: Purchase response code:7

11-02 09:23:01.138  1503  1514 E ActivityTrigger: activityResumeTrigger: not whiteListedcom.hoge.foo/com.google.firebase.MessagingUnityPlayerActivity/202

11-02 09:23:01.139  1503  1514 E ActivityTrigger: activityResumeTrigger: not whiteListedcom.hoge.foo/com.google.firebase.MessagingUnityPlayerActivity/202

11-02 09:23:01.140  1503  1514 I InputDispatcher: Focus entered window: Window{e76c79a u0 com.hoge.foo/com.google.firebase.MessagingUnityPlayerActivity}

11-02 09:23:01.236 28181 28181 I UnityIAP: onActivityResult

 

Thank you for the information, we will investigate.

 

I am facing this issue myself now, and am about to add the suggested fix (adding a call to 'ConfirmPendingPurchase' in the 'OnPurchaseFailed' callback if the reason is 'DuplicateTransaction').
But one thing is not clear - what do you mean by:
"Please make sure that you won't unlock a product multi times for one purchase."
?
Thanks

 

You can disregard that statement. There is no harm in attempting to unlock a product multiple times. "Unlock" means "give the product to the user".

 

We are able to reproduce this issue pretty easily by disconnecting the internet while the performing the purchase on Android, and the proposed solution of calling 'ConfirmPendingPurchase' in the 'OnPurchaseFailed' callback is not working...

This is the flow:
1. Initiate a purchase on product x
2. While it is trying to confirm the purchase with the store, turn off the internet
3. The "OnPurchaseFailed" callback is triggered with the reason "Unknown"
4. Reconnect the internet
5. Initiate a purchase on product x
6. The "OnPurchaseFailed" callback is triggered with the reason "DuplicateTransaction"
7. Call "ConfirmPendingPurchase" from the failed callback with the given product
8. Initiate a purchase on product x
9. The "OnPurchaseFailed" callback is triggered with the reason "DuplicateTransaction"
10. Call "ConfirmPendingPurchase" from the failed callback with the given product
11. Restart the app
12. Initiate a purchase on product x
13. The "OnPurchaseFailed" callback is triggered with the reason "DuplicateTransaction"
14. Call "ConfirmPendingPurchase" from the failed callback with the given product

No matter what we do, or how many times we call "ConfirmPendingPurchase", we get the duplicate error.

In the adb logs, I see that indeed the product was purchased and not consumed:
03-15 11:13:45.749 8415 8415 I UnityIAP: onActivityResult
03-15 11:13:45.749 8415 8415 I UnityIAP: Purchase canceled - Response: 7:Item Already Owned
03-15 11:13:45.749 8415 8415 I UnityIAP: onIabPurchaseFinished: false
03-15 11:13:45.749 8415 8415 I UnityIAP: 7:Item Already Owned (response: 7:Item Already Owned)
03-15 11:13:45.749 8415 8415 I UnityIAP: Purchase response code:7

The only thing that releases this product and allows us to purchase it again is clearing the app's data.

It appears that "ConfirmPendingPurchase" isn't consuming the item, probably because the plugin doesn't believe the item was purchased (due to the initial failed response).
Yet, we should still be able to consume an item, even if the iap plugin doesn't think it was purchased...

Any idea why the suggested solution isn't working? Any way to work around this?
(btw, we are using the latest iap plugin, version 2.0.6)

Thanks

 

It was never suggested to call ConfirmPendingPurchase in a Failed callback event, apologies on the confusion. That would never be expected to succeed. You generally call it during ProcessPurchase during the next initialization when a Pending product is processed. We are hoping to improve the disconnected scenario that you mention in an upcoming release.

 

Yet this suggestion will not solve our problem, since ProcessPurchase is never called after getting a product stuck in this manner.
Even after restarting the app and initializing the iap plugin, ProcessPurchase is not called because as far as the plugin is concerned, the initial purchase did not succeed. There is no pending product.

So there is absolutely no way to solve this issue? There's no way to consume an already purchased product?
This seems rather odd...

 

We are hoping to improve the network disconnect behavior in the next release. This behavior would generally be expected to be a rare event, but possible. If you are just testing, it is recommended to create an additional product or use a new device user profile if the product is non-consumable, like a Subscription, that can only be purchased once. Additional purchase attempts for a non-consumable would be considered a duplicate transaction and not allowed.

 

Thanks for the info.
Anyways, we are able to reproduce this pretty easily, and when dealing with a lot of users and crappy internet it can be pretty common. So to avoid having to ask our users to clear their Google Play data (because that's the only way to enable purchasing this item again after reaching this state) we implemented a native workaround.

Here is my solution, in case anyone else is facing this issue:

In out activity class, in onCreate, we bind the billing service:

Code (CSharp):

1. Intent serviceIntent = new Intent("com.android.vending.billing.InAppBillingService.BIND");
2. serviceIntent.setPackage("com.android.vending");
3. bindService(serviceIntent, mServiceConn, Context.BIND_AUTO_CREATE);

using the service connection object:

Code (CSharp):

1. ServiceConnection mServiceConn = new ServiceConnection() {
2.     @Override
3.     public void onServiceConnected(ComponentName name, IBinder service) {
4.         Log.d(TAG, "Service connected: " + name);
5.         mService = IInAppBillingService.Stub.asInterface(service);
6.     }
7.  
8.     @Override
9.     public void onServiceDisconnected(ComponentName name) {
10.         Log.d(TAG, "Service disconnected: " + name);
11.         mService = null;
12.     }
13. };

And added a consume function with this logic:

Code (CSharp):

1. ArrayList<String> dataList = new ArrayList<>();
2.  
3. Bundle ownedItems = mService.getPurchases(version, packageName, "inapp", null);
4. if (ownedItems.getInt("RESPONSE_CODE") == 0) {
5.     // Get the list of purchased items
6.     ArrayList<String> purchaseDataList = ownedItems.getStringArrayList("INAPP_PURCHASE_DATA_LIST");
7.  
8.     if (purchaseDataList != null) {
9.         Log.d(TAG, "Adding products: " + purchaseDataList.size());
10.         dataList.addAll(purchaseDataList);
11.     }
12. }
13.  
14. Bundle historyItems = mService.getPurchaseHistory(version, packageName, "inapp", null, new Bundle());
15. if (historyItems.getInt("RESPONSE_CODE") == 0) {
16.     ArrayList<String> historyDataList = historyItems.getStringArrayList("INAPP_PURCHASE_DATA_LIST");
17.  
18.     if (historyDataList != null) {
19.         Log.d(TAG, "Adding history: " + historyDataList.size());
20.         dataList.addAll(historyDataList);
21.     }
22. }
23.  
24. for (int i = 0; i < dataList.size(); i++) {
25.     String purchaseData = dataList.get(i);
26.     JSONObject o = new JSONObject(purchaseData);
27.     String currProductId = o.optString("productId");
28.    
29.     if (currProductId != null && currProductId.equals(productId)) {
30.         String purchaseToken = o.optString("purchaseToken", o.optString("token"));
31.         int consumeCode = mService.consumePurchase(version, packageName, purchaseToken);
32.         if (consumeCode == 0) {
33.             Log.i(TAG, "Product consumed: " + productId);
34.         }
35.         break;
36.     }
37. }

Then all we had to do was call this consume function when getting the duplicate transaction error with the relevant product id.

It would be nice to have a similar functionality provided by the plugin, since this is assuming several things that might break in future versions of the plugin...

 

I noticed there was an update for the IAP plugin (version 1.22.0) so I updated to the new version, and now when reproducing the internet problem I described above, I no longer get callbacks from the purchasing plugin.

Here are the adb logs from trying to initialized the plugin:

Code (CSharp):

1. 04-01 12:11:34.444 26527  6307 I Unity   : UnityIAP Version: 1.22.0
2. 04-01 12:11:34.789 26527  6307 I Unity   : Using configuration builder objects
3. 04-01 12:11:34.791 26527  6307 I UnityIAP: Requesting 6 products
4. 04-01 12:11:34.791 26527  6307 I UnityIAP: QueryInventory: 6
5. 04-01 12:11:34.791 26527 26780 I UnityIAP: invoking callback
6. 04-01 12:11:34.791 26527 26780 I UnityIAP: Querying owned items, item type: inapp
7. 04-01 12:11:34.791 26527 26780 I UnityIAP: Package name: com.example.mobile
8. 04-01 12:11:34.791 26527 26780 I UnityIAP: Calling getPurchases with continuation token: null
9. 04-01 12:11:34.855 26527 26780 I UnityIAP: Owned items response: 0
10. 04-01 12:11:34.855 26527 26780 I UnityIAP: Sku is owned: com.example.1
11. 04-01 12:11:34.855 26527 26780 I UnityIAP: Sku is owned: com.example.2
12. 04-01 12:11:34.855 26527 26780 I UnityIAP: Sku is owned: com.example.3
13. 04-01 12:11:34.855 26527 26780 I UnityIAP: Continuation token: null
14. 04-01 12:11:34.855 26527 26780 I UnityIAP: Querying SKU details.
15. 04-01 12:11:34.894 26527 26780 I UnityIAP: Querying owned items, item type: subs
16. 04-01 12:11:34.894 26527 26780 I UnityIAP: Package name: com.example.mobile
17. 04-01 12:11:34.894 26527 26780 I UnityIAP: Calling getPurchases with continuation token: null
18. 04-01 12:11:35.017 26527 26780 I UnityIAP: Owned items response: 0
19. 04-01 12:11:35.017 26527 26780 I UnityIAP: Continuation token: null
20. 04-01 12:11:35.017 26527 26780 I UnityIAP: Querying SKU details.
21. 04-01 12:11:35.024 26527 26780 I UnityIAP: Querying owned items' purchase history, item type: subs
22. 04-01 12:11:35.024 26527 26780 I UnityIAP: Package name: com.example.mobile
23. 04-01 12:11:35.024 26527 26780 I UnityIAP: Calling getPurchaseHistory with continuation token: null
24. 04-01 12:11:35.139 26527 26780 I UnityIAP: Purchase history response: 0
25. 04-01 12:11:35.139 26527 26780 I UnityIAP: Continuation token: null
26. 04-01 12:11:35.139 26527 26780 I UnityIAP: Querying owned items' purchase history, item type: inapp
27. 04-01 12:11:35.139 26527 26780 I UnityIAP: Package name: com.example.mobile
28. 04-01 12:11:35.139 26527 26780 I UnityIAP: Calling getPurchaseHistory with continuation token: null
29. 04-01 12:11:35.383 26527 26780 I UnityIAP: Purchase history response: 0
30. 04-01 12:11:35.384 26527 26780 I UnityIAP: Continuation token: null
31. 04-01 12:11:35.384 26527 26780 I UnityIAP: onQueryInventoryFinished: true
32. 04-01 12:11:35.384 26527 26780 I UnityIAP: Inventory refresh successful. (response: 0:OK)
33. [B]04-01 12:11:35.396 26527 26780 E Unity   : NullReferenceException: Object reference not set to an instance of an object.
34. 04-01 12:11:35.396 26527 26780 E Unity   :   at UnityEngine._AndroidJNIHelper.InvokeJavaProxyMethod (UnityEngine.AndroidJavaProxy proxy, System.IntPtr jmethodName, System.IntPtr jargs) [0x00000] in <00000000000000000000000000000000>:0
35. 04-01 12:11:35.396 26527 26780 E Unity   :  
36. 04-01 12:11:35.396 26527 26780 E Unity   : (Filename: currently not available on il2cpp Line: -1)
37. 04-01 12:11:35.396 26527 26780 E Unity[/B]   :

For now I reverted the update, but can you please fix this issue so we can update to the new version?
Thanks

 

Please provide specific steps to reproduce with a new project.