Open sampsao opened 4 years ago
Any updates on this? @Qing451800
Thanks for letting us know. We're aware of the ANR issue just not sure who bad it is. The plugin wraps the Play Billing Library. I think the ANR might be caused by this: https://issuetracker.google.com/142601982 We will look into this. It may take some time since reproducing ANR issue and verifying fix is extremely hard.
I'm thinking that a simply fix might be to remove the retry connection logic: https://github.com/google/play-unity-plugins/blob/master/GooglePlayPlugins/com.google.play.billing/Runtime/Scripts/GooglePlayStoreImpl.cs#L84 If possible, we'd be appreciated that if you can test this.
Meanwhile, we can try to improve the retry logic and have reasonable timeout handling logic.
Hi, Thank you for the response. If this is of any help, we seem to be experiencing these a lot on Samsung, Huawei and Honor devices, with Android OS 8.0, 8.1, 9.0 and 10. A lot of the devices seem to be flagship devices from recent years (Galaxy S8, S9, S8+, S10e etc). I read the issue tracker thread and it seems that if that is the case, then I can not do much about it? Since we're not executing the thread calls ourselves but rather the plugin/library does it on its own. We also see these reports starting from the native onBillingSetupFinished calls also. If the reason is that the connection is retried too soon after the disconnect, I can definitely try to remove the retry logic out. Do you have any recommendation how to handle the situation afterwards? Like should I wait X seconds/frames and try to initialize the connection again or is there other steps that should be taken before trying to connect the store again? And should I try to change the timeout value that is set in the constants file?
Then some extra feedback: the documentation at https://developer.android.com/google/play/billing/unity is quite messy. I think there should be a clear, start-to-finish example how to use this plugin instead of referring and directing people to read the Unity documentations. It is quite hard to understand what are all the necessary changes between this and the base Unity IAP that need to be made to get the plugin working properly, when you could have a very simple example showing the basic initialization and purchase logic in one code block. Also I think enabling the deferred purchases should be the default setting in the plugin as they seem to be required for the purchases to work properly. And being able to register all the callback only after the initialization is finished properly is also a bit problematic since there is a possibility that it will not be called again on reconnect. If you can provide me with your professional opinion on the reconnection logic, it would be much appreciated. Thank you again.
Thanks for the information. We did some investigation in ANRs but couldn't repro these issues. We're keeping working on it to optimize the threading in PBL and PBL plugin. Regarding to the devices and Android OS, is that because those devices are more used in the the market?
Could you provide more details about the reports that you saw from onBillingSetupFinished?
For the retry logic, for now it immediately retries connection. You can add a delayed reconnection with a couple of seconds (5~10s) and see whether it helps or not.
We will add a sample app that integrates with Play Billing Unity plugin soon to GitHub.
Hey, joining this conversation because we are getting the same (or similar?) issues showing up in our unity diagnostics. I'll share what information we have to see if it helps. Apologies in advance for the text dump!
The error we receive in Unity Diagnostics is: AndroidJavaException: java.lang.IllegalStateException: Too many receivers, total of 1000, registered for pid: numbergoeshere, callerPackage: com.company.product (removed the company and number just in case).
From Unity Diagnostics, we get stack traces that read the following:
Managed Stack Trace:
java.lang.IllegalStateException: Too many receivers, total of 1000, registered for pid: 5897, callerPackage: com.sticksports.stickcricketlive
android.os.Parcel.createException(Parcel.java:2095)
android.os.Parcel.readException(Parcel.java:2055)
android.os.Parcel.readException(Parcel.java:2003)
android.app.IActivityManager$Stub$Proxy.registerReceiver(IActivityManager.java:5076)
android.app.ContextImpl.registerReceiverInternal(ContextImpl.java:1552)
android.app.ContextImpl.registerReceiver(ContextImpl.java:1513)
android.app.ContextImpl.registerReceiver(ContextImpl.java:1501)
android.content.ContextWrapper.registerReceiver(ContextWrapper.java:638)
com.android.billingclient.api.zze.zza(com.android.billingclient:billing@@3.0.0:5)
com.android.billingclient.api.zzd.zza(com.android.billingclient:billing@@3.0.0:5)
com.android.billingclient.api.BillingClientImpl.startConnection(com.android.billingclient:billing@@3.0.0:58)
com.unity3d.player.ReflectionHelper.nativeProxyInvoke(Native Method)
com.unity3d.player.ReflectionHelper.a(Unknown Source:0)
com.unity3d.player.ReflectionHelper$1.invoke(Unknown Source:24)
java.lang.reflect.Proxy.invoke(Proxy.java:1006)
$Proxy19.onBillingServiceDisconnected(Unknown Source)
com.android.billingclient.api.BillingClientImpl$zza.onServiceDisconnected(com.android.billingclient:billing@@3.0.0:11)
android.app.LoadedApk$ServiceDispatcher.doDeath(LoadedApk.java:2086)
android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:2101)
android.os.Handler.handleCallback(Handler.java:883)
android.os.Handler.dispatchMessage(Handler.java:100)
android.os.Looper.loop(Looper.java:228)
android.app.ActivityThread.main(ActivityThread.java:7782)
java.lang.reflect.Method.invoke(Native Method)
com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
com.android.internal.os.ZygoteInit.main(ZygoteInit.java:981)
UnityEngine.AndroidJNISafe.CheckException () (at <00000000000000000000000000000000>:0)
UnityEngine.AndroidJavaObject._Call (System.String methodName, System.Object[] args) (at <00000000000000000000000000000000>:0)
Google.Play.Billing.GooglePlayStoreImpl.InstantiateBillingClientAndMakeConnection () (at <00000000000000000000000000000000>:0)
System.Action.Invoke () (at <00000000000000000000000000000000>:0)
System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) (at <00000000000000000000000000000000>:0)
UnityEngine.AndroidJavaProxy.Invoke (System.String methodName, System.Object[] args) (at <00000000000000000000000000000000>:0)
UnityEngine._AndroidJNIHelper.InvokeJavaProxyMethod (UnityEngine.AndroidJavaProxy proxy, System.IntPtr jmethodName, System.IntPtr jargs) (at <00000000000000000000000000000000>:0)
Rethrow as TargetInvocationException: Google.Play.Billing.Internal.BillingClientStateListener.onBillingServiceDisconnected()
UnityEngine.AndroidJavaProxy.Invoke (System.String methodName, System.Object[] args) (at <00000000000000000000000000000000>:0)
UnityEngine._AndroidJNIHelper.InvokeJavaProxyMethod (UnityEngine.AndroidJavaProxy proxy, System.IntPtr jmethodName, System.IntPtr jargs) (at <00000000000000000000000000000000>:0)
or
Managed Stack Trace:
java.lang.IllegalStateException: Too many receivers, total of 1000, registered for pid: 17613, callerPackage: com.sticksports.stickcricketlive
android.os.Parcel.createException(Parcel.java:2095)
android.os.Parcel.readException(Parcel.java:2055)
android.os.Parcel.readException(Parcel.java:2003)
android.app.IActivityManager$Stub$Proxy.registerReceiver(IActivityManager.java:5076)
android.app.ContextImpl.registerReceiverInternal(ContextImpl.java:1552)
android.app.ContextImpl.registerReceiver(ContextImpl.java:1513)
android.app.ContextImpl.registerReceiver(ContextImpl.java:1501)
android.content.ContextWrapper.registerReceiver(ContextWrapper.java:638)
com.android.billingclient.api.zze.zza(com.android.billingclient:billing@@3.0.0:5)
com.android.billingclient.api.zzd.zza(com.android.billingclient:billing@@3.0.0:5)
com.android.billingclient.api.BillingClientImpl.startConnection(com.android.billingclient:billing@@3.0.0:58)
com.unity3d.player.ReflectionHelper.nativeProxyInvoke(Native Method)
com.unity3d.player.ReflectionHelper.a(Unknown Source:0)
com.unity3d.player.ReflectionHelper$1.invoke(Unknown Source:24)
java.lang.reflect.Proxy.invoke(Proxy.java:1006)
$Proxy13.onBillingServiceDisconnected(Unknown Source)
com.android.billingclient.api.BillingClientImpl$zza.onServiceDisconnected(com.android.billingclient:billing@@3.0.0:11)
android.app.LoadedApk$ServiceDispatcher.doDeath(LoadedApk.java:2086)
android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:2101)
android.os.Handler.handleCallback(Handler.java:883)
android.os.Handler.dispatchMessage(Handler.java:100)
android.os.Looper.loop(Looper.java:228)
android.app.ActivityThread.main(ActivityThread.java:7782)
java.lang.reflect.Method.invoke(Native Method)
com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
com.android.internal.os.ZygoteInit.main(ZygoteInit.java:981)
Caused by: android.os.RemoteException: Remote stack trace:
com.android.server.am.ActivityManagerService.registerReceiver(ActivityManagerService.java:15576)
android.app.IActivityManager$Stub.onTransact(IActivityManager.java:2009)
com.android.server.am.ActivityManagerService.onTransact(ActivityManagerService.java:2998)
com.android.server.am.OppoActivityManagerService.onTransact(OppoActivityManagerService.java:99)
android.os.Binder.execTransactInternal(Binder.java:1021)
UnityEngine.AndroidJNISafe.CheckException () (at <00000000000000000000000000000000>:0)
UnityEngine.AndroidJavaObject._Call (System.String methodName, System.Object[] args) (at <00000000000000000000000000000000>:0)
Google.Play.Billing.GooglePlayStoreImpl.InstantiateBillingClientAndMakeConnection () (at <00000000000000000000000000000000>:0)
System.Action.Invoke () (at <00000000000000000000000000000000>:0)
System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) (at <00000000000000000000000000000000>:0)
UnityEngine.AndroidJavaProxy.Invoke (System.String methodName, System.Object[] args) (at <00000000000000000000000000000000>:0)
UnityEngine._AndroidJNIHelper.InvokeJavaProxyMethod (UnityEngine.AndroidJavaProxy proxy, System.IntPtr jmethodName, System.IntPtr jargs) (at <00000000000000000000000000000000>:0)
Rethrow as TargetInvocationException: Google.Play.Billing.Internal.BillingClientStateListener.onBillingServiceDisconnected()
UnityEngine.AndroidJavaProxy.Invoke (System.String methodName, System.Object[] args) (at <00000000000000000000000000000000>:0)
UnityEngine._AndroidJNIHelper.InvokeJavaProxyMethod (UnityEngine.AndroidJavaProxy proxy, System.IntPtr jmethodName, System.IntPtr jargs) (at <00000000000000000000000000000000>:0)
Both stack traces report similar logs referencing the code @Qing451800 suggested removing.
Though not exclusive to, a lot of our devices that report these issues are RealMe devices. Though we have seen some on Huawei and the odd Lonovo device.
They are commonly accompanied by logs such as:
Type | Timestamp | Frame | Message |
---|---|---|---|
Error | Sep 28, 2020, 07:57:56.490 | 33615 | Google Play Store: Failed to connect to service with error code 'BillingUnavailable' and debug message: 'Google Play In-app Billing API version is less than 3'. |
Error | Sep 28, 2020, 07:57:56.741 | 33615 | Google Play Store: Failed to connect to service with error code 'BillingUnavailable' and debug message: 'Google Play In-app Billing API version is less than 3'. |
Error | Sep 28, 2020, 07:57:57.000 | 33615 | Google Play Store: Failed to connect to service with error code 'BillingUnavailable' and debug message: 'Google Play In-app Billing API version is less than 3'. |
Error | Sep 28, 2020, 07:57:57.248 | 33615 | Google Play Store: Failed to connect to service with error code 'BillingUnavailable' and debug message: 'Google Play In-app Billing API version is less than 3'. |
Warning | Sep 28, 2020, 07:57:57.545 | 33615 | Google Play Store: Service disconnected, retrying connection... |
Error | Sep 28, 2020, 07:57:57.580 | 33615 | Google Play Store: Service is unavailable. |
Warning | Sep 28, 2020, 07:57:58.933 | 33615 | Google Play Store: Service disconnected, retrying connection... |
Error | Sep 28, 2020, 07:57:58.965 | 33615 | Google Play Store: Service is unavailable. |
Warning | Sep 28, 2020, 07:57:59.296 | 33615 | Google Play Store: Service disconnected, retrying connection... |
Error | Sep 28, 2020, 07:57:59.323 | 33615 | Google Play Store: Service is unavailable. |
Our best guess was that this is occuring on devices that either don't have google play installed, or have an out of date google play version installed. Though this might only be happening on devices google doesn't support (maybe?), the error in logic is still in the code here and it does clog up our crash reports.
I think the reconnect logic must be stacking up in a way that it constantly resubscribes to the OnBillingServiceDisconnected event and never unsubscribes from it perhaps? And then eventually after retrying a large number of times, we get these crash reports.
That's all the information I have. Let me know if I can provide any more information to further assist. =)
Thank you very much. These stack trace is very help. It looks like we should limit the # of times when we do reconnecting. We will make some fixes in next release and we will update the thread when we have updates.
Hi @Qing451800 do we have any update about this issue? Thanks
We have the same issue. We are going to limit the number of reconnects ourselves.
I believe @abittman is on the right track for why it's possible to end up with too many registered receivers. I'm going to be testing out https://github.com/google/play-unity-plugins/compare/master...PerBlue:reconnect_clear_receiver as a possible fix to that.
We've added exponential delay between reconnects and ANR's don't bother us anymore.
@Hinidu how did you do that any refference ??
@jsteinich any success that you have tried??
@kashifundefined We've been running that code change on a public beta app for about a month now and haven't seen the Too many receivers
error in that time.
@jsteinich I am getting ANR at com.android.billingclient.api.billingClientStateListener.onBillingSetupFinished
What would be workaround for this, am using latest IAP plugin
@kashifundefined until a fix is added to the library, you'll want to modify the code to either add delay like @Hinidu mentioned or apply the patch that I linked earlier.
Having very similar issues triggered by onBillingSetupFinished, onBillingServiceDisconnected and onSkuDetailsResponse. This leads to the ANR threshold being exceeded. Any help would be appreciated.
GPBL 3.1.2 UnityIAP 2.2.2
at com.unity3d.player.ReflectionHelper.nativeProxyInvoke (Native method) at com.unity3d.player.ReflectionHelper.a (unavailable) at com.unity3d.player.ReflectionHelper$1.invoke (unavailable) at java.lang.reflect.Proxy.invoke (Proxy.java:1006) at com.android.billingclient.api.BillingClientStateListener.onBillingSetupFinished at com.android.billingclient.api.zzae.run at android.os.Handler.handleCallback (Handler.java:873) at android.os.Handler.dispatchMessage (Handler.java:99) at android.os.Looper.loop (Looper.java:214) at android.app.ActivityThread.main (ActivityThread.java:7050) at java.lang.reflect.Method.invoke (Native method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:494) at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:965)
at com.unity3d.player.ReflectionHelper.nativeProxyInvoke (Native method) at com.unity3d.player.ReflectionHelper.a (unavailable) at com.unity3d.player.ReflectionHelper$1.invoke (unavailable) at java.lang.reflect.Proxy.invoke (Proxy.java:1006) at com.android.billingclient.api.BillingClientStateListener.onBillingServiceDisconnected at com.android.billingclient.api.zzah.onServiceDisconnected at android.app.LoadedApk$ServiceDispatcher.doDeath (LoadedApk.java:1975) at android.app.LoadedApk$ServiceDispatcher$RunConnection.run (LoadedApk.java:1990) at android.os.Handler.handleCallback (Handler.java:883) at android.os.Handler.dispatchMessage (Handler.java:100) at android.os.Looper.loop (Looper.java:223) at android.app.ActivityThread.main (ActivityThread.java:7562) at java.lang.reflect.Method.invoke (Native method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:539) at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:950)
at com.unity3d.player.ReflectionHelper.nativeProxyInvoke (Native method) at com.unity3d.player.ReflectionHelper.a (unavailable) at com.unity3d.player.ReflectionHelper$1.invoke (unavailable) at java.lang.reflect.Proxy.invoke (Proxy.java:1006) at com.android.billingclient.api.SkuDetailsResponseListener.onSkuDetailsResponse at com.android.billingclient.api.zzac.run at android.os.Handler.handleCallback (Handler.java:883) at android.os.Handler.dispatchMessage (Handler.java:100) at android.os.Looper.loop (Looper.java:227) at android.app.ActivityThread.main (ActivityThread.java:7822) at java.lang.reflect.Method.invoke (Native method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:492) at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1026)
Thanks for the link @jsteinich, I am giving it a try. I also noticed that after 500 connection failures (due to luck of internet) the app gets crashed: JNI ERROR (app bug): global reference table overflow (max=51200) so I also added simple checking if intenret is available (Application.internetReachability) before making initialization attempt. BTW I was using 60 sec internval and that was not enough. Within couple of days I will update this post and tell if your patch and internet availability checking resolved both onBillingServiceDisconnected and onBillingSetupFinished issues.
UPD: 3 days in production and all ANRs gone. The patch is working but new non fatal error appeared in UnityEngine.Purchasing.ReflectionUtils.HasMethodInInterface when app loses focus.
@YehudaK could you please tell what changes in code are you add (it in Admob or only google plugins)? I'm just working on a large application where there are several analysts, and some of my own solutions, and have already spent a lot of time parsing my logs.
@YehudaK could you please tell what changes in code are you add (it in Admob or only google plugins)?
Sorry for the delay, just saw your message. If you are still experience the same issue, here is the link to patch which @jsteinich suggested. I can confirm that changing that single line fixes the problem completely.
We have a similar issue where if users play offline the JNI fills up with google billing errors
10-19 22:23:12.136 6149 6686 F PlayGames.FCM2: java_vm_ext.cc:638] JNI ERROR (app bug): global reference table overflow (max=51200)global reference table dump:
10-19 22:23:12.136 6149 6686 F PlayGames.FCM2: java_vm_ext.cc:638] Last 10 entries (of 51200):
10-19 22:23:12.136 6149 6686 F PlayGames.FCM2: java_vm_ext.cc:638] 51199: 0x13626510 java.lang.Class
Hello,
We updated to use this IAP extension plugin to provide better experience for players who encounter pending/deferred transactions in different countries. After we started using the plugin we have noticed a dramatic increase on our ANR reports in Google Play Console. Judging by this log, it seems that the play billing is responsible for this: `"main" prio=5 tid=1 Native | group="main" sCount=1 dsCount=0 flags=1 obj=0x75d2d4b8 self=0x7225c14c00 | sysTid=12272 nice=0 cgrp=default sched=0/0 handle=0x72ac6c8560 | state=S schedstat=( 46514845398 38837452674 39787 ) utm=1525 stm=3126 core=4 HZ=100 | stack=0x7ff43a6000-0x7ff43a8000 stackSize=8MB | held mutexes=
00 pc 000000000001eeec /system/lib64/libc.so (syscall+28)
01 pc 00000000000d7e24 /system/lib64/libart.so (art::ConditionVariable::WaitHoldingLocks(art::Thread*)+148)
02 pc 0000000000374500 /system/lib64/libart.so (art::JNI::GetStringUTFChars(_JNIEnv, _jstring, unsigned char*)+472)
03 pc 00000000003058f8 /data/app/-Jg8O9BrmDmclaRW4y7n8qA==/lib/arm64/libunity.so (???)
04 pc 000000000030b310 /data/app/-Jg8O9BrmDmclaRW4y7n8qA==/lib/arm64/libunity.so (???)
05 pc 0000000003fe3c14 /data/app/-Jg8O9BrmDmclaRW4y7n8qA==/lib/arm64/libil2cpp.so (_AndroidJNIHelper_InvokeJavaProxyMethod_mF92923091814A5E820890D2CCE76C7A589F03192+368)
06 pc 0000000002d7eb54 /data/app/-Jg8O9BrmDmclaRW4y7n8qA==/lib/arm64/libil2cpp.so (RuntimeInvoker_FalseIntPtr_t_RuntimeObject_IntPtr_t_IntPtr_t(void ()(), MethodInfo const, void*, void**)+44)
07 pc 0000000002e5fba8 /data/app/-Jg8O9BrmDmclaRW4y7n8qA==/lib/arm64/libil2cpp.so (il2cpp::vm::Runtime::Invoke(MethodInfo const, void, void, Il2CppException)+104)
08 pc 00000000003851f4 /data/app/-Jg8O9BrmDmclaRW4y7n8qA==/lib/arm64/libunity.so (???)
09 pc 0000000000376f28 /data/app/-Jg8O9BrmDmclaRW4y7n8qA==/lib/arm64/libunity.so (???)
10 pc 00000000003046a4 /data/app/-Jg8O9BrmDmclaRW4y7n8qA==/lib/arm64/libunity.so (???)
at com.unity3d.player.ReflectionHelper.nativeProxyInvoke (Native method) at com.unity3d.player.ReflectionHelper.a (unavailable) at com.unity3d.player.ReflectionHelper$1.invoke (unavailable) at java.lang.reflect.Proxy.invoke (Proxy.java:1006) at com.android.billingclient.api.BillingClientStateListener.onBillingServiceDisconnected at com.android.billingclient.api.BillingClientImpl$zza.onServiceDisconnected at android.app.LoadedApk$ServiceDispatcher.doDeath (LoadedApk.java:1858) at android.app.LoadedApk$ServiceDispatcher$RunConnection.run (LoadedApk.java:1873) at android.os.Handler.handleCallback (Handler.java:873) at android.os.Handler.dispatchMessage (Handler.java:99) at android.os.Looper.loop (Looper.java:214) at android.app.ActivityThread.main (ActivityThread.java:7050) at java.lang.reflect.Method.invoke (Native method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:494) at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:965)` This is quite unfortunate as this seems to be a problem mostly on newer Android OS versions (Android 8.0 -->) thus providing a bad experience for the more probable paying customers. As these ANRs never happened before when we used the standard Unity IAP, it seems obvious the problem is within this plugin or the base play billing library itself. From my understanding these are usually the cause of blocking the UI thread? I see the GooglePlayBillingInventory.cs and GooglePlayBillingUtil.cs quite heavily lock variables before calling native Java side of things. Could it be that the plugin doesn't survive this properly in certain situations? This is a huge problem for us, as the ANR reports drop the app below the good behaviour line and therefore affects the store presence. And I don't know if it is related to this, but sometimes the Initialization of the plugin fails quite badly. We have experienced issues where if initialization fails or the store is disconnected and reconnected, the plugin doesn't keep reference to the deferred purchase callback like it should or even call the initialization success callback again. Instead, the plugin throws an exception and users are forced to restart the app to get around this, hoping the initialization works the next time. I tried to make some workarounds for this issue so that the deferred callback would not get nulled, but we still encounter this from time to time. I'm quite sure that I have everything set up the correct way, but the documentation of the plugin is a bit vague and doesn't have any information regarding how to handle these. If you could shed some light on these issues it would be most appreciated.