firebase / quickstart-android

Firebase Quickstart Samples for Android
https://firebase.google.com
Apache License 2.0
8.87k stars 7.32k forks source link

ANR #594

Closed LiuDongCai closed 4 years ago

LiuDongCai commented 6 years ago
Broadcast of Intent { act=com.google.android.c2dm.intent.RECEIVE flg=0x11000010 pkg=com.addcn.android.house591 cmp=com.addcn.android.house591/com.google.firebase.iid.FirebaseInstanceIdReceiver (has extras) }
com.google.firebase.iid.FirebaseInstanceIdReceiver
samtstern commented 6 years ago

@LiuDongCai this is not enough information to debug. Are you getting this from Crashlytics or something? Is this a new issue? If so, does it correspond to an SDK update?

LiuDongCai commented 6 years ago

@samtstern "main" prio=5 tid=1 Native | group="main" sCount=1 dsCount=0 flags=1 obj=0x72f69730 self=0x7532ac3a00 | sysTid=17865 nice=0 cgrp=default sched=0/0 handle=0x75374189b0 | state=S schedstat=( 1887679225 229007884 1067 ) utm=162 stm=26 core=1 HZ=100 | stack=0x7fea58c000-0x7fea58e000 stackSize=8MB | held mutexes=

00 pc 0000000000068e18 /system/lib64/libc.so (__epoll_pwait+8)

01 pc 000000000001fa98 /system/lib64/libc.so (epoll_pwait+48)

02 pc 0000000000015c1c /system/lib64/libutils.so (_ZN7android6Looper9pollInnerEi+144)

03 pc 0000000000015b04 /system/lib64/libutils.so (_ZN7android6Looper8pollOnceEiPiS1_PPv+108)

04 pc 0000000000111de4 /system/lib64/libandroid_runtime.so (???)

05 pc 00000000001e605c /system/framework/arm64/boot-framework.oat (Java_android_os_MessageQueue_nativePollOnce__JI+140)

at android.os.MessageQueue.nativePollOnce (Native method) at android.os.MessageQueue.next (MessageQueue.java:375) at android.os.Looper.loop (Looper.java:225) at android.app.ActivityThread.main (ActivityThread.java:6572) at java.lang.reflect.Method.invoke (Native method) at com.android.internal.os.Zygote$MethodAndArgsCaller.run (Zygote.java:240) at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:767)

This is anr in Google play. It just happen at Android 8.0. And my Firebase Version: implementation 'com.google.firebase:firebase-core:16.0.1' implementation 'com.google.firebase:firebase-messaging:17.1.0' implementation 'com.google.firebase:firebase-perf:16.0.0'

samtstern commented 6 years ago

@LiuDongCai while I do believe this is a real issue for you, it's not possible to begin fixing it unless we can reproduce the issue as well.

See this page for more information on how to file an actionable bug report: https://stackoverflow.com/help/mcve

nmr8acme commented 5 years ago

You are literally the 4th result on the first page of search results for "Broadcast of Intent { act=com.google.android.c2dm.intent.RECEIVE flg=0x11000010 ANR". It would be good of you to take on a bit of responsibility and investigate.

If you read the news group thread at search result 3 it looks like Vitalii may have already debugged it for you. https://groups.google.com/d/msg/firebase-talk/5mo7-z8gqFA/RugthckUCgAJ. I cannot overstate my disappointment with such apathy.

samtstern commented 5 years ago

@nmr8acme sorry that you're disappointed. It certainly wasn't "apathy" that led me to close this issue, it was a lack of the information we need to debug the issue. A copy-pasted dump from a crash report just isn't enough.

Your link to the google groups post (which I hadn't seen before) contains much more information and is very helpful! I will use this to file a more detailed bug report with the authors of the InstanceID SDK and see if they can fix it.

Looking at the source for FirebaseInstanceIdReceiver I can see that the potentially problematic code has been changed a few times since Vitali deobfuscated it, so it's possible a fix is already in. I will report back.

nmr8acme commented 5 years ago

Requiring a repro is a rather high bar to set for what looks like a tricky bug. Thank you for pursuing it. FWIW I am experiencing this bug on firebase-iid 16.0.0. I'll try updating, which, to complain more, would be substantially easier if InstanceIDListenerService hadn't been deprecated.

samtstern commented 5 years ago

Here are some initial thoughts I got from the engineer who wrote the code involved here (slightly paraphrased to remove internal terminology).

It seems that we're aware of the general issue and we're using a number of techniques to try and avoid this, but there are still cases where the broadcast doesn't finish fast enough and we see ANRs. We are continuing to investigate.


An FCM message broadcast comes in via the FirebaseInstanceIdReceiver which routes it to FirebaseMessagingService (and/or FirebaseInstanceIdService if it's IID related).

If the app is running on a device <O or is targeting <O we just use startService, they get a background service, virtually no chance of an ANR as the receiver will always finish quickly.

[...]

For normal priority messages, we keep the broadcast going (via goAsync), and bind to their service. This gives 60s for their service to run before the broadcast ANRs. As a fail safe we also set a 9s timer to finish the broadcast if their code is still running to avoid ANRs, at this stage there's no guarantee Android won't just kill their app even though their code is still running - they could use a foreground service, or schedule the work for later if they wanted to.

The [recent changes mean] that for high priority messages, where [the system gives] the app a short whitelist that allows them to take wake locks, hit the network, start services, etc. we use startService, similar to what we used to do which should greatly reduce the rate of ANRs. If this fails for whatever reason we fall back to using the bind approach above.

This is much more important here as for high priority messages we use a foreground broadcast that triggers an ANR in the receiver after 10s (which is why we set the timeout to 9s) - but worse than that can cause system issues as foreground broadcasts are expected to be fast.

Even with that change though I still hear some reports of ANRs, which I haven't been able to diagnose.

samtstern commented 5 years ago

@nmr8acme our reccomendations right now:

nmr8acme commented 5 years ago

Great advice, thanks. Part of what makes this a tough bug is that the stack traces in the ANR tombstones are "empty", i.e. main thread is not blocked, just sitting there in the looper, which is a bit baffling.

  #00  pc 000000000004a4d0  /system/lib/libc.so (__epoll_pwait+20)
   #01  pc 000000000001bcd5  /system/lib/libc.so (epoll_pwait+60)
   #02  pc 000000000001bd05  /system/lib/libc.so (epoll_wait+12)
   #03  pc 0000000000010407  /system/lib/libutils.so (_ZN7android6Looper9pollInnerEi+118)
   #04  pc 00000000000102f9  /system/lib/libutils.so (_ZN7android6Looper8pollOnceEiPiS1_PPv+32)
   #05  pc 00000000000e465d  /system/lib/libandroid_runtime.so (_ZN7android18NativeMessageQueue8pollOnceEP7_JNIEnvP8_jobjecti+24)
   #06  pc 00000000001a8b45  /system/framework/arm/boot-framework.oat (Java_android_os_MessageQueue_nativePollOnce__JI+92)
   at android.os.MessageQueue.nativePollOnce (Native method)
   at android.os.MessageQueue.next (MessageQueue.java:325)
   at android.os.Looper.loop (Looper.java:142)
   at android.app.ActivityThread.main (ActivityThread.java:6938)
   at java.lang.reflect.Method.invoke (Native method)
   at com.android.internal.os.Zygote$MethodAndArgsCaller.run (Zygote.java:327)
   at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1374)
zjinGZ commented 5 years ago

We had the same ANR issue "main" prio=5 tid=1 Native | group="main" sCount=1 dsCount=0 flags=1 obj=0x72885518 self=0xf098f000 | sysTid=13756 nice=0 cgrp=default sched=0/0 handle=0xf4b944a4 | state=S schedstat=( 1682598454 870098442 3521 ) utm=127 stm=40 core=3 HZ=100 | stack=0xff63a000-0xff63c000 stackSize=8MB | held mutexes=

00 pc 0000000000049bcc /system/lib/libc.so (__epoll_pwait+20)

01 pc 000000000001b4c9 /system/lib/libc.so (epoll_pwait+60)

02 pc 000000000001b4f9 /system/lib/libc.so (epoll_wait+12)

03 pc 0000000000010163 /system/lib/libutils.so (android::Looper::pollInner(int)+118)

04 pc 0000000000010055 /system/lib/libutils.so (android::Looper::pollOnce(int, int, int, void**)+32)

05 pc 00000000000b95e1 /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv, _jobject, int)+24)

06 pc 000000000019b9fd /system/framework/arm/boot-framework.oat (Java_android_os_MessageQueue_nativePollOnce__JI+92)

at android.os.MessageQueue.nativePollOnce (Native method) at android.os.MessageQueue.next (MessageQueue.java:379) at android.os.Looper.loop (Looper.java:144) at android.app.ActivityThread.main (ActivityThread.java:7555) at java.lang.reflect.Method.invoke (Native method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:469) at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:963)

connor-git-yaml commented 5 years ago

same thing to me

Broadcast of Intent { act=com.google.android.c2dm.intent.RECEIVE flg=0x11000010 pkg=com.tencent.qqlivei18n cmp=com.tencent.qqlivei18n/com.google.firebase.iid.FirebaseInstanceIdReceiver (has extras) }

"main" prio=5 tid=1 Native | group="main" sCount=1 dsCount=0 flags=1 obj=0x722f2840 self=0xa5544000 | sysTid=5909 nice=0 cgrp=default sched=0/0 handle=0xa9cbb4b8 | state=S schedstat=( 0 0 0 ) utm=21 stm=21 core=3 HZ=100 | stack=0xbe356000-0xbe358000 stackSize=8MB | held mutexes=

00 pc 0000000000049974 /system/lib/libc.so (__epoll_pwait+20)

01 pc 000000000001ba15 /system/lib/libc.so (epoll_pwait+60)

02 pc 000000000001ba45 /system/lib/libc.so (epoll_wait+12)

03 pc 000000000001002d /system/lib/libutils.so (android::Looper::pollInner(int)+120)

04 pc 000000000000ff1d /system/lib/libutils.so (android::Looper::pollOnce(int, int, int, void**)+32)

05 pc 00000000000ba081 /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv, _jobject, int)+24)

06 pc 0000000000176265 /system/framework/arm/boot-framework.oat (Java_android_os_MessageQueue_nativePollOnce__JI+92)

at android.os.MessageQueue.nativePollOnce (Native method) at android.os.MessageQueue.next (MessageQueue.java:325) at android.os.Looper.loop (Looper.java:142) at android.app.ActivityThread.main (ActivityThread.java:7000) at java.lang.reflect.Method.invoke (Native method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:441) at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1408)

hvar90 commented 5 years ago

@samtstern i have some operations that could take more than 10 seconds but i use AsyncTask to execute those operations even i tried with WorkManager and the result is the same i got a lot of ARNs this problem happens even with this library com.google.android.gms.ads i got this similar ARN

Broadcast of Intent { act=com.google.android.c2dm.intent.RECEIVE flg=0x10000010

pkg=schan.main cmp=schan.main/com.google.firebase.iid.FirebaseInstanceIdReceiver (has extras) ### }, VisibleToUser

com.google.firebase.iid.FirebaseInstanceIdReceiver


Motorola Moto X Play (lux), Android 7.1

"main" tid=1 WaitingForGc 
"main" prio=5 tid=1 WaitingForGcToComplete
  | group="main" sCount=1 dsCount=0 obj=0x73ffd700 self=0xa5504400
  | sysTid=25274 nice=-10 cgrp=default sched=0/0 handle=0xa8207534
  | state=S schedstat=( 337564206094 73424441135 444182 ) utm=29001 stm=4754 core=0 HZ=100
  | stack=0xbe37d000-0xbe37f000 stackSize=8MB
  | held mutexes=
  #00  pc 00000000000174d4  /system/lib/libc.so (syscall+28)
  #01  pc 00000000000b6fc9  /system/lib/libart.so (_ZN3art17ConditionVariable16WaitHoldingLocksEPNS_6ThreadE+92)
  #02  pc 0000000000186839  /system/lib/libart.so (_ZN3art2gc4Heap25WaitForGcToCompleteLockedENS0_7GcCauseEPNS_6ThreadE+236)
  #03  pc 0000000000192b79  /system/lib/libart.so (_ZN3art2gc4Heap19WaitForGcToCompleteENS0_7GcCauseEPNS_6ThreadE+172)
  #04  pc 000000000018ce8d  /system/lib/libart.so (_ZN3art2gc4Heap22AllocateInternalWithGcEPNS_6ThreadENS0_13AllocatorTypeEbjPjS5_S5_PPNS_6mirror5ClassE+84)
  #05  pc 0000000000127b8d  /system/lib/libart.so (_ZN3art2gc4Heap24AllocObjectWithAllocatorILb1ELb1ENS_6mirror21SetStringCountVisitorEEEPNS3_6ObjectEPNS_6ThreadEPNS3_5ClassEjNS0_13AllocatorTypeERKT1_+2360)
  #06  pc 000000000029c9cd  /system/lib/libart.so (_ZN3art6mirror6String14AllocFromUtf16EPNS_6ThreadEiPKt+84)
  #07  pc 000000000027cdff  /system/lib/libart.so (_ZN3art3JNI9NewStringEP7_JNIEnvPKti+430)
  #08  pc 000000000009334d  /system/lib/libandroid_runtime.so (???)
  #09  pc 0000000000c03db5  /data/dalvik-cache/arm/system@framework@boot.oat (Java_android_os_Parcel_nativeReadString__J+88)
  at android.os.Parcel.nativeReadString (Native method)
  at android.os.Parcel.readString (Parcel.java:1738)
  at android.content.pm.ApplicationInfo.<init> (ApplicationInfo.java:1019)
  at android.content.pm.ApplicationInfo.<init> (ApplicationInfo.java)
  at android.content.pm.ApplicationInfo$1.createFromParcel (ApplicationInfo.java:996)
  at android.content.pm.ApplicationInfo$1.createFromParcel (ApplicationInfo.java:995)
  at android.content.pm.PackageInfo.<init> (PackageInfo.java:352)
  at android.content.pm.PackageInfo.<init> (PackageInfo.java)
  at android.content.pm.PackageInfo$1.createFromParcel (PackageInfo.java:332)
  at android.content.pm.PackageInfo$1.createFromParcel (PackageInfo.java:331)
  at android.content.pm.IPackageManager$Stub$Proxy.getPackageInfo (IPackageManager.java:2493)
  at android.app.ApplicationPackageManager.getPackageInfoAsUser (ApplicationPackageManager.java:139)
  at android.app.ApplicationPackageManager.getPackageInfo (ApplicationPackageManager.java:132)
  at com.google.android.gms.common.GooglePlayServicesUtilLight.zza (unavailable:34)
  at com.google.android.gms.common.GooglePlayServicesUtilLight.isGooglePlayServicesAvailable (unavailable:22)
  at com.google.android.gms.common.GoogleApiAvailabilityLight.isGooglePlayServicesAvailable (unavailable:5)
  at com.google.android.gms.internal.ads.zzazt.zzc (unavailable:67)
  at com.google.android.gms.internal.ads.zzys.zzd (unavailable:35)
  at com.google.android.gms.internal.ads.zzabb.zza (unavailable:100)
  at com.google.android.gms.ads.BaseAdView.loadAd (unavailable:15)
  at com.google.android.gms.ads.AdView.loadAd (unavailable:18)
  at schan.main.ChatActivity.loadAds (ChatActivity.java:614)
  at schan.main.ChatActivity.onCreate (ChatActivity.java:551)
  at android.app.Activity.performCreate (Activity.java:6687)
  at android.app.Instrumentation.callActivityOnCreate (Instrumentation.java:1140)
  at android.app.ActivityThread.performLaunchActivity (ActivityThread.java:2631)
  at android.app.ActivityThread.handleLaunchActivity (ActivityThread.java:2743)
  at android.app.ActivityThread.-wrap12 (ActivityThread.java)
  at android.app.ActivityThread$H.handleMessage (ActivityThread.java:1490)
  at android.os.Handler.dispatchMessage (Handler.java:102)
  at android.os.Looper.loop (Looper.java:154)
  at android.app.ActivityThread.main (ActivityThread.java:6165)
  at java.lang.reflect.Method.invoke! (Native method)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run (ZygoteInit.java:888)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:778)
"Jit thread pool worker thread 0" tid=2 Native 
"FinalizerWatchdogDaemon" tid=5 Sleeping 
"FinalizerDaemon" tid=6 WaitingForGc 
"ReferenceQueueDaemon" tid=7 Waiting 
"Binder:25274_1" tid=8 Native 
"Binder:25274_2" tid=9 Native 
"Profile Saver" tid=10 Native 
"FirebaseInstanceId" tid=12 Waiting 
"pool-2-thread-1" tid=13 Waiting 
"MessengerIpcClient" tid=16 TimedWaiting 
"GoogleApiHandler" tid=22 Native 
"Chrome_IOThread" tid=23 Native 
"PlatformServiceBridgeHandlerThread" tid=24 Native 
"GAC_Executor[0]" tid=26 Waiting 
"ConnectivityManager" tid=27 Native 
"CleanupReference" tid=28 Waiting 
"AudioThread" tid=29 Native 
"Chrome_InProcRendererThread" tid=30 Native 
"Chrome_InProcGpuThread" tid=31 Native 
"GAC_Executor[1]" tid=33 Waiting 
"Binder:25274_3" tid=34 Native 
"LooperProvider" tid=38 Native 
"AdWorker(NG) #1" tid=45 WaitingForGc 
"RenderThread" tid=48 Native 
"JavaBridge" tid=58 Native 
"Signal Catcher" tid=3 Runnable 
"HeapTaskDaemon" tid=4 WaitingForGc 
jyy195822328 commented 5 years ago

"main" tid=1 Native "main" prio=5 tid=1 Native | group="main" sCount=1 dsCount=0 flags=1 obj=0x72ec1858 self=0xaee44000 | sysTid=10258 nice=0 cgrp=default sched=0/0 handle=0xb35b74b8 | state=S schedstat=( 0 0 0 ) utm=20 stm=78 core=0 HZ=100 | stack=0xbe281000-0xbe283000 stackSize=8MB | held mutexes=

00 pc 0000000000049974 /system/lib/libc.so (__epoll_pwait+20)

01 pc 000000000001ba15 /system/lib/libc.so (epoll_pwait+60)

02 pc 000000000001ba45 /system/lib/libc.so (epoll_wait+12)

03 pc 000000000001002d /system/lib/libutils.so (android::Looper::pollInner(int)+120)

04 pc 000000000000ff1d /system/lib/libutils.so (android::Looper::pollOnce(int, int, int, void**)+32)

05 pc 00000000000ba081 /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv, _jobject, int)+24)

06 pc 0000000000176265 /system/framework/arm/boot-framework.oat (Java_android_os_MessageQueue_nativePollOnce__JI+92)

at android.os.MessageQueue.nativePollOnce (Native method) at android.os.MessageQueue.next (MessageQueue.java:325) at android.os.Looper.loop (Looper.java:142) at android.app.ActivityThread.main (ActivityThread.java:7000) at java.lang.reflect.Method.invoke (Native method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:441) at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1408)

notapro commented 5 years ago

I am also facing this issue. 95% of the ANRs that are getting reported on my Google Play Console are referring to this issue.

`"main" tid=1 Blocked "main" prio=5 tid=1 Blocked | group="main" sCount=1 dsCount=0 flags=1 obj=0x743a7660 self=0xe7fc9000 | sysTid=5740 nice=0 cgrp=default sched=0/0 handle=0xec9f1494 | state=S schedstat=( 792615932 491011320 1059 ) utm=14 stm=65 core=5 HZ=100 | stack=0xff077000-0xff079000 stackSize=8MB | held mutexes= at android.app.QueuedWork.processPendingWork (QueuedWork.java:245)

All these ANRs show that the main thread is either waiting or blocked. Is there a status update on this issue?

lizheng98 commented 5 years ago

@samtstern hi, I have the same issue.

ANR because of Broadcast of Intent { act=com.google.android.c2dm.intent.RECEIVE in FirebaseInstanceIdReceiver

"main" prio=5 tid=1 Native | group="main" sCount=1 dsCount=0 flags=1 obj=0x73faf638 self=0xe8c77000 | sysTid=26244 nice=0 cgrp=default sched=0/0 handle=0xed1084bc | state=S schedstat=( 718806623 1179973180 1307 ) utm=34 stm=37 core=3 HZ=100 | stack=0xff0dc000-0xff0de000 stackSize=8MB | held mutexes=

00 pc 0000000000018ebc /system/lib/libc.so (syscall+28)

01 pc 00000000000b380d /system/lib/libart.so (_ZN3art17ConditionVariable16WaitHoldingLocksEPNS_6ThreadE+88)

02 pc 00000000003bfa27 /system/lib/libart.so (_ZN3artL12GoToRunnableEPNS_6ThreadE+306)

03 pc 00000000003bf8c5 /system/lib/libart.so (_ZN3art12JniMethodEndEjPNS_6ThreadE+8)

04 pc 000000000081bda1 /system/framework/arm/boot-framework.oat (Java_android_os_BinderProxy_transactNative__ILandroid_os_Parcel_2Landroid_os_Parcel_2I+144)

at android.os.BinderProxy.transactNative (BinderProxy.java) at android.os.BinderProxy.transact (BinderProxy.java:761) at android.app.IActivityManager$Stub$Proxy.addPackageDependency (IActivityManager.java:6867) at android.app.LoadedApk.createOrUpdateClassLoaderLocked (LoadedApk.java:613) at android.app.LoadedApk.getClassLoader (LoadedApk.java:711)

Remarks:the resources that reference firebase are as follows: classpath 'com.google.gms:google-services:4.0.1' //firebase remoteconfig implementation 'com.google.firebase:firebase-core:16.0.4' implementation 'com.google.firebase:firebase-config:16.0.1' implementation 'com.google.firebase:firebase-messaging:18.0.0' implementation 'com.google.firebase:firebase-ads:16.0.1'

compileSdkVersion: 28, buildToolsVersion: "28.0.3", targetSdkVersion : 26,

PratyeshSingh commented 5 years ago

hi Everyone, I have also the same issue.

ANR because of Broadcast of Intent { act=com.google.android.c2dm.intent.RECEIVE in FirebaseInstanceIdReceiver

"main" prio=5 tid=1 Waiting | group="main" sCount=1 dsCount=0 obj=0x751a5000 self=0xb8d3a630 | sysTid=29578 nice=-4 cgrp=apps sched=0/0 handle=0xb6fb6ec8 | state=S schedstat=( 1264064036 710641375 2251 ) utm=96 stm=30 core=0 HZ=100 | stack=0xbe31d000-0xbe31f000 stackSize=8MB | held mutexes= at java.lang.Object.wait! (Native method)

//firebase remoteconfig implementation 'com.google.firebase:firebase-messaging:19.0.1' implementation 'com.google.firebase:firebase-core:17.0.0' implementation 'com.google.firebase:firebase-appindexing:19.0.0' implementation 'com.google.firebase:firebase-config:18.0.0'

    compileSdkVersion = 28
    minSdkVersion = 17
    targetSdkVersion = 28

Please help me on it if anyone of you are having solution of this. Thanks in advance.

doniwinata0309 commented 5 years ago

Hi, we also got many report on play console with same error. We already updated to firebase 17.0.1 I also profiled our app start cpu call and no operation blocking more than 10 second. Any other advice what we should do about it ?

ntanduc2288 commented 5 years ago

Facing the same issue after upgrade FCM to 17.+ and targetSDKVertion to 28

esafirm commented 5 years ago

Is there any fix for this? Got the same ANR in Android 9 only

Tougee commented 5 years ago

Any solutions? Lots of same ANRs in my google play console ANR list firebase version 17.2.1

reachzhai commented 4 years ago

have same problem with firebase 18.2.0

tamtom commented 4 years ago

any update?

chenglinq commented 4 years ago

@samtstern

triggers an ANR in the receiver after 10s (which is why we set the timeout to 9s)

Correct me if i am wrong, the 9s timer is started in FirebaseInstanceIdReceiver#onReceive(before binding FirebaseMessagingService), but the 10s ANR timer is started before Application#onCreate(which is called before FirebaseInstanceIdReceiver#onReceive). So if Application#onCreate consumes more than 1 second, the 9s timer may not be triggered before the 10s ANR timeout.

deepak786 commented 4 years ago

Our app is also facing a lot of ANRs from this

Screen Shot 2020-04-06 at 4 52 50 PM

is there any update?

xiaoxiaohua333 commented 4 years ago

image

Migrate from Fabric ?

RijoshEnfin commented 4 years ago

Reason: Broadcast of Intent { act=com.google.android.c2dm.intent.RECEIVE flg=0x11000010 com.google.firebase.iid.FirebaseInstanceIdReceiver (has extras) }

Our app is facing a ANR issue like this.what is the solution?

smilewaver commented 4 years ago

still encounter this ANR frequently. we suspected that finishReceiver is not invoke correctly, but not find the root cause yet. And another doubt maybe the app startup cost too long if broadcast come when the app is not alive?

smilewaver commented 4 years ago

Maybe the QueueWork blocked by heavy work?

tuancoltech commented 4 years ago

@LiuDongCai @RijoshEnfin @smilewaver Have you tried upgrading your firebase-messaging to the latest version: com.google.firebase:firebase-messaging:20.1.7 ? They said the ANR issues were fixed.

Screenshot from 2020-05-14 16-07-44

@samtstern Correct me if I'm wrong.

tuancoltech commented 4 years ago

BTW, beside the ANR log that everybody else has already shared, here is an extra log I got regarding this ANR:

"ActivityManager" prio=5 tid=12 Native | group="main" sCount=1 dsCount=0 flags=1 obj=0x12cc7548 self=0x75f9f4d800 | sysTid=5921 nice=-2 cgrp=default sched=0/0 handle=0x75da0ba4f0 | state=S schedstat=( 5360246218928 1545171760396 6169400 ) utm=237405 stm=298619 core=6 HZ=100 | stack=0x75d9fb7000-0x75d9fb9000 stackSize=1041KB | held mutexes= kernel: (couldn't read /proc/self/task/5921/stack) native: #00 pc 0000000000071448 /system/lib64/libc.so (recvfrom+8) native: #01 pc 0000000000001c54 /system/lib64/libdebuggerd_client.so (debuggerd_trigger_dump(int, DebuggerdDumpType, unsigned int, android::base::unique_fd_impl)+1252) native: #02 pc 0000000000002868 /system/lib64/libdebuggerd_client.so (dump_backtrace_to_file_timeout(int, DebuggerdDumpType, int, int)+104) native: #03 pc 000000000011e760 /system/lib64/libandroid_runtime.so (android::dumpTraces(_JNIEnv, int, _jstring, int, DebuggerdDumpType)+124) native: #04 pc 000000000011dff8 /system/lib64/libandroid_runtime.so (android::android_os_Debug_dumpJavaBacktraceToFileTimeout(_JNIEnv, _jobject, int, _jstring*, int)+28) at android.os.Debug.dumpJavaBacktraceToFileTimeout(Native method) at com.android.server.am.ActivityManagerService.dumpJavaTracesTombstoned(ActivityManagerService.java:8292) at com.android.server.am.ActivityManagerService.dumpStackTraces(ActivityManagerService.java:8382) at com.android.server.am.ActivityManagerService.dumpStackTraces(ActivityManagerService.java:8169) at com.android.server.am.AppErrors.appNotResponding(AppErrors.java:1216) at com.android.server.am.BroadcastQueue$AppNotResponding.run(BroadcastQueue.java:318) at android.os.Handler.handleCallback(Handler.java:873) at android.os.Handler.dispatchMessage(Handler.java:99) at android.os.Looper.loop(Looper.java:216) at android.os.HandlerThread.run(HandlerThread.java:65) at com.android.server.ServiceThread.run(ServiceThread.java:44)

Delayed Historical Broadcast foreground #0: BroadcastRecord{f870e5f u95 com.google.android.c2dm.intent.RECEIVE} to user 95 Intent { act=com.google.android.c2dm.intent.RECEIVE flg=0x11000010 pkg=com.zing.zalo (has extras) } caller=com.google.android.gms 27128:com.google.android.gms.persistent/u0a45 pid=27128 uid=10045 enqueueClockTime=2020-05-14 11:44:28.313 dispatchClockTime=2020-05-14 11:44:28.314 dispatchTime=-10s2ms (+1ms since enq) finishTime=-1ms (+10s1ms since disp) anrCount=1 resultTo=null resultCode=0 resultData=null resultAbort=false ordered=true sticky=false initialSticky=false nextReceiver=1 receiver=null Timeout #0: (manifest), [disp=-10s0ms, fin=-1ms, dur=+9s999ms] priority=0 preferredOrder=0 match=0x108000 specificIndex=-1 isDefault=false ActivityInfo: name=com.google.firebase.iid.FirebaseInstanceIdReceiver packageName=com.zing.zalo enabled=true exported=true directBootAware=false permission=com.google.android.c2dm.permission.SEND resizeMode=RESIZE_MODE_RESIZEABLE requestTransientBarDelay=-1

zainForAndro commented 4 years ago

i am using 20.1.5 version of firebase-messaging and still encountering the same issue. This anr is frequently reported on play console.

tuancoltech commented 4 years ago

i am using 20.1.5 version of firebase-messaging and still encountering the same issue. This anr is frequently reported on play console.

Hi @zainForAndro , how about 20.1.7 ?

PratyeshSingh commented 4 years ago

@samtstern & Support team, Did you get any fix for the above reported issue, seems keep increasing the cases?

need-attention

Thanks

samtstern commented 4 years ago

My earlier comments on this bug are, unfortunately, the best I will be able to offer. If anyone is able to find a minimal reproducible example for this there may be more to discuss: https://stackoverflow.com/help/minimal-reproducible-example

PratyeshSingh commented 4 years ago

@samtstern
Please find the details log if this is helpful for now, It is difficult to reproduce. But this is being logged in Google play console.

"main" prio=5 tid=1 Native | group="main" sCount=1 dsCount=0 obj=0x741a22a0 self=0xb7a48590 | sysTid=29991 nice=0 cgrp=default sched=0/0 handle=0xb6f62b34 | state=S schedstat=( 0 0 0 ) utm=9 stm=35 core=0 HZ=100 | stack=0xbe6ac000-0xbe6ae000 stackSize=8MB | held mutexes=

00 pc 0000000000042908 /system/lib/libc.so (__ioctl+8)

01 pc 000000000004966d /system/lib/libc.so (ioctl+14)

02 pc 000000000001ea21 /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+132)

03 pc 000000000001f087 /system/lib/libbinder.so (android::IPCThreadState::waitForResponse(android::Parcel, int)+38)

04 pc 000000000001f23d /system/lib/libbinder.so (android::IPCThreadState::transact(int, unsigned int, android::Parcel const&, android::Parcel*, unsigned int)+124)

05 pc 000000000001a1cf /system/lib/libbinder.so (android::BpBinder::transact(unsigned int, android::Parcel const&, android::Parcel*, unsigned int)+30)

06 pc 0000000000088e21 /system/lib/libandroid_runtime.so (???)

07 pc 0000000000d93f01 /data/dalvik-cache/arm/system@framework@boot.oat (Java_android_os_BinderProxy_transactNative__ILandroid_os_Parcel_2Landroid_os_Parcel_2I+140)

at android.os.BinderProxy.transactNative (BinderProxy.java) at android.os.BinderProxy.transact (BinderProxy.java:503) at android.content.pm.IPackageManager$Stub$Proxy.getApplicationInfo (IPackageManager.java:2319) at android.app.ApplicationPackageManager.getApplicationInfo (ApplicationPackageManager.java:292) at com.google.android.gms.common.wrappers.PackageManagerWrapper.getApplicationInfo (PackageManagerWrapper.java:4) at com.google.android.gms.internal.measurement.zzx.zza (zzx.java:232) at com.google.android.gms.internal.measurement.zzx.zzi (zzx.java:185)

Screenshot 2020-05-31 at 10 06 58 AM
smilewaver commented 4 years ago

@tuancoltech we have try com.google.firebase:firebase-messaging:20.1.7 in a small release. which has no effect. and we guess that one possible scene is, AMS call client to deal the broadcast, and the client maybe blocked by any time cost op in main thread. when the block pass, AMS already assume the client ANR.

Yrlec commented 4 years ago

@LiuDongCai while I do believe this is a real issue for you, it's not possible to begin fixing it unless we can reproduce the issue as well.

I'm glad you're not working for Boeing.

bwpandamb commented 4 years ago

We meet the same thing in the project and update it to 20.1.7 is useless. This problem seems to have existed for at least a year, do you have the plan to solve it?

RodolfoGS commented 4 years ago

Same issue

mwshubham commented 4 years ago

+1

RoyJing commented 4 years ago

Same issue,do you have the plan to solve it?

RoyJing commented 4 years ago

@RoyJing I am using implementation 'com.google.firebase:firebase-messaging:20.2.3' and it is fixed there check release notes.

Hi,bro. Did you see after the app was released that the GooglePlay console didn't have this problem? And can you tell me about your app's DAU? Thank you very much! Because there are too many users of our app, we dare not upgrade directly, for fear of any new problems

xuduo commented 4 years ago

My app use a lot of high priority fcm notification with only payload.I wonder if this happens when user click the notification to open the app or when user receive the notification then the app is process is started? About 70% ANR are from the FirebaseInstanceIdReceiver.

xuduo commented 4 years ago

I've tried to change the fcm notification priority from high to normal, all the ANRS caused by FirebaseInstanceIdReceiver disapeared, except one which has a stacktrace that I think could be resolved. But the notification recieve rate dropped about 10%.

andy3466 commented 4 years ago

I've also tried to change the fcm notification priority from high to normal, the ANRS caused by FirebaseInstanceIdReceiver decreased a lot. But the notification receive rate dropped about 30%, which has a huge affect to our app...

Bradmrhong commented 4 years ago

@RoyJing I am using implementation 'com.google.firebase:firebase-messaging:20.2.3' and it is fixed there check release notes.

Hi, @mwshubham, I check the release note and it says "Fixed an issue that caused an app to crash when a user tapped on a received notification." I'm aware that it solves the crash instead of ANR issues. I just want to confirm if the updates will help to reduce ANR.

Also, I read the comments from @samtstern which says the devices with >26 will trigger more ANRs instead of <26'devices. But as I see in the play console, many ANRs are reported every day from Android 6 devices with SDK 23. And it's been a year since last suggestion. Do we have any updates on this issue?

Looking forward to your reply :)

arsundram commented 4 years ago

We are still getting this error even after

I checked the play console. We didnt get the ANR from the last two releases. @Bradmrhong Looks like this is fixed in the latest versions.

It is still coming in the latest version "com.google.firebase:firebase-messaging:20.2.4" Anyone else still getting this ANR? The Play Console is filled with this ANR. It is affecting our play store listing.

Bradmrhong commented 4 years ago

Same as @arsundram. We have already updated to 20.2.4 but still getting this kind of ANRs at the same high rate. I checked again in StackOverflow and someone says need to update play-service too? Any more ideas about this?

heiyeliuying commented 4 years ago

ANR +1 too many .

RodolfoGS commented 4 years ago

I updated to com.google.firebase:firebase-messaging:20.2.4 but the ANRs continue.

Broadcast of Intent { act=com.google.android.c2dm.intent.RECEIVE flg=0x11000010 pkg=xxx cmp=xxx/com.google.firebase.iid.FirebaseInstanceIdReceiver (has extras) }

in com.google.firebase.iid.FirebaseInstanceIdReceiver