Firebase-android-sdk: IllegalStateException in FirebaseInstanceId

[quibi-jlk]

[REQUIRED] Step 2: Describe your environment

• Android Studio version: Tried on both 3.6.3 and 4.0.0-beta05
• Firebase Component: Firebase IID (via messaging or installations
• Component version:
  We have direct deps on:

FIREBASE_ANALYTICS = "17.3.0"
FIREBASE_MESSAGING = "20.1.5"
FIREBASE_PERF = "19.0.6"
FIREBASE_CRASHLYTICS = "17.0.0-beta04"

Firebase installations resolves to 16.2.1

[REQUIRED] Step 3: Describe the problem

We have a significant number of crash reports in crashlytics with this obfuscated stack trace:

Fatal Exception: java.lang.IllegalStateException
       at com.google.firebase.iid.FirebaseInstanceId.zzl(FirebaseInstanceId.java:70)
       at com.google.firebase.iid.FirebaseInstanceId.getId(FirebaseInstanceId.java:48)
       at com.google.firebase.perf.internal.zzf.zzbv(zzf.java:181)
       at com.google.firebase.perf.internal.zzf.zzbu(zzf.java:44)
       at com.google.firebase.perf.internal.zzf.zzc(zzf.java:195)
       at com.google.firebase.perf.internal.zze.run(zze.java:2)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
       at java.lang.Thread.run(Thread.java:919)

This is currently by far our largest open crash cluster

It is very similar to https://github.com/firebase/firebase-android-sdk/issues/1339#, but I was advised by @TKBurner to create a new ticket since that was was marked closed in an older sdk version. I'm happy to provide any additional data that might help here.

Steps to reproduce:

We don't have a local repro for this issue, but it's certainly affecting people in the wild.

cc @andirayo who worked on the original issue

[google-oss-bot]

I found a few problems with this issue:

• I couldn't figure out how to label this issue, so I've labeled it for a human to triage. Hang tight.
• This issue does not seem to follow the issue template. Make sure you provide all the required information.

[andirayo]

@quibi-jlk
I deobfuscated the your stacktrace and it is either v20.1.4 or v20.1.5 of FirebaseInstanceId.
Those versions contain the original fix.
You name FIS version as 16.2.1 which should also contain the fix.

For some reason, other than you only @hetang reported a similar issue.
On the other hand, your comment in #1339 immediately got 3 upvotes.

Apparently we have a regression of #1339 (or #1355 did not fix all scenarios).

[andirayo]

@quibi-jlk
We will immediately be looking into this, but we cannot promise you any timeline.
The next scheduled release will be FirebaseInstanceId (and FirebaseMessaging) v20.1.8, scheduled for May 21, 2020.

Thus, if this is an urgent issue for you, I recommend you to downgrade to versions of Firebase SDKs before the introduction of the infrastructure service FirebaseInstallations:

You can lock FirebaseInstanceId to v20.0.2 or use older versions of Firebase SDKs (which should have the same effect):

• FirebaseMessaging < v20.1.1
• Analytics < 17.4.0
• FirePerf < 19.0.7
• Crashlytics < 17.0.0

[quibi-jlk]

Thanks so much for the quick response and action on this @andirayo! I'll try to check out whether there are any problems with downgrading our deps. If there are, I think waiting until May 21st wouldn't be the end of the world on our end.

Just to be clear, when you say < you don't mean <= right? For example, with Crashlytics, this would kick us back to a pretty early beta or alpha, right?

[ashwinraghav]

@quibi-jlk are you able to provide the dependencies graph for us?

./gradlew :app:dependencies

[andirayo]

@quibi-jlk :
Yes, I meant smaller, not equal. Those version numbers are the ones that started using FirebaseInstallations.

Q2) Do you happen to have more extensive logs for the crash (background: we are trying to reproduce the issue locally)?
Q3) Is there any other pattern for the crashses that you can identify, e.g. "errors only happen for Android versions 7 and 8"?

[ramanpreetSinghKhinda]

FYI: Another dev reported this with the exact same stacktraces and line numbers in v20.1.5 of IID -> https://github.com/firebase/firebase-android-sdk/issues/1454#issuecomment-623380042

[quibi-jlk]

Hi folks, sorry for the delay, I've been pulled away to some other high-priority work. Here are answers to these questions:

Q1 (deps) - Here are our firebase-relevant deps:

+--- com.google.firebase:firebase-analytics:17.3.0@aar
+--- com.google.firebase:firebase-messaging:20.1.5@aar
+--- com.google.firebase:firebase-perf:19.0.6@aar
+--- com.google.firebase:firebase-crashlytics:17.0.0-beta04@aar
+--- com.google.firebase:firebase-config:19.0.4@aar
+--- com.google.firebase:firebase-iid:20.1.5@aar
+--- com.google.firebase:firebase-datatransport:17.0.3@aar
+--- com.google.firebase:firebase-installations:16.2.1@aar
+--- com.google.firebase:firebase-abt:19.0.0@aar
+--- com.google.firebase:firebase-common:19.3.0@aar
+--- com.google.firebase:firebase-installations-interop:16.0.0@aar
+--- com.google.firebase:firebase-iid-interop:17.0.0@aar
+--- com.google.firebase:firebase-measurement-connector:18.0.0@aar
+--- com.google.firebase:firebase-components:16.0.0@aar
+--- com.google.firebase:firebase-encoders-json:16.1.0@aar

Q2) Unfortunately we have no local repro, so we only have what crashlytics gives us here, which is this stack trace.

Q3) We don't see any correlation by device type, sdk version, etc. However, we do see that 97% of the crashes are while the app is in the background (usually right after starting up a background sync job). We also see this log in about 50% of the reports:

E/m: Unrecoverable error connecting to Google Play services (e.g. the old version of the service doesn't support getting AdvertisingId).

This might be a red herring, but it's interesting to me that many of these are running an old gmscore apk.

[ankitaj224]

@quibi-jlk can you please paste the stack trace of all threads as seen in crashlytics?

[quibi-jlk]

Attaching file with all 40 threads @ankitaj224
allthreadsfirebase.log

[vkryachko]

@ankitaj224 it's interesting that none of the threads are blocked on the FileLock, in fact the thread pool is just empty waiting for tasks. Could it be the case that the getId() task completion source just does not get completed for some reason?

Another strange fact is that there appear to be 2 threads in the firebase-installations-executor even though it's configured to be single-threaded afaict. wdyt?

[fangor16]

I'm also having this issue.

These are my dependencies regarding Firebase

com.google.firebase:firebase-analytics:17.3.0
com.google.firebase:firebase-crashlytics:17.0.0-beta04
com.google.firebase:firebase-perf:19.0.6

Q2) This is all the stack trace I could get from Firebase Crashlytics : https://pastebin.com/UMkjvpZV

Q3) 92% crash happens while app is in background.
OS version -:
54% Android 10
31% Android 9
15% Android 8

For firebase-core, which version would you recommend to use?

[artour-bakiev]

Also have this issue - 33 unique events reported so far.

The stack trace is:

java.lang.IllegalStateException: null
    at com.google.firebase.iid.FirebaseInstanceId.zzl(com.google.firebase:firebase-iid@@20.1.5:70)
    at com.google.firebase.iid.FirebaseInstanceId.getId(com.google.firebase:firebase-iid@@20.1.5:48)
    at com.google.firebase.perf.internal.zzf.zzbu(com.google.firebase:firebase-perf@@19.0.5:181)
    at com.google.firebase.perf.internal.zzf.zzbt(com.google.firebase:firebase-perf@@19.0.5:44)
    at com.google.firebase.perf.internal.zzf.zzc(com.google.firebase:firebase-perf@@19.0.5:195)
    at com.google.firebase.perf.internal.zze.run(com.google.firebase:firebase-perf@@19.0.5:2)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
    at java.lang.Thread.run(Thread.java:764)

The dependencies are:

+--- com.google.firebase:firebase-messaging:20.1.5
...
|    |    \--- com.google.firebase:firebase-encoders-json:16.0.0
...
|    +--- com.google.firebase:firebase-common:19.3.0
...
|    |    \--- com.google.firebase:firebase-components:16.0.0
...
|    +--- com.google.firebase:firebase-components:16.0.0 (*)
|    +--- com.google.firebase:firebase-datatransport:17.0.3
...
|    |    \--- com.google.firebase:firebase-common:19.3.0 (*)
|    +--- com.google.firebase:firebase-encoders-json:16.0.0 (*)
|    +--- com.google.firebase:firebase-iid:[20.1.5] -> 20.1.5
...
|    |    +--- com.google.firebase:firebase-common:19.3.0 (*)
|    |    +--- com.google.firebase:firebase-components:16.0.0 (*)
|    |    +--- com.google.firebase:firebase-iid-interop:17.0.0
...
|    |    +--- com.google.firebase:firebase-installations:16.2.1
...
|    |    |    +--- com.google.firebase:firebase-common:19.3.0 (*)
|    |    |    +--- com.google.firebase:firebase-components:16.0.0 (*)
|    |    |    \--- com.google.firebase:firebase-installations-interop:16.0.0
...
|    |    \--- com.google.firebase:firebase-installations-interop:16.0.0 (*)
|    +--- com.google.firebase:firebase-installations:16.2.1 (*)
|    +--- com.google.firebase:firebase-installations-interop:16.0.0 (*)
|    \--- com.google.firebase:firebase-measurement-connector:18.0.0
...
+--- com.google.firebase:firebase-messaging:{strictly 20.1.5} -> 20.1.5 (c)

[quibi-jlk]

@ankitaj224 do you have any updates here?

[visumickey]

Another issue similar to this #1494 .

[ankitaj224]

@quibi-jlk Sorry for the delayed response. I have few pending changes and should be able to release fix as part of v16.4.0 of FirebaseInstallations (and FirebaseMessaging v20.2.1) on June 18, 2020.

I ll keep this thread posted on the updates.

[ankitaj224]

@quibi-jlk : We have some ideas around what might be causing the issue but we couldn't successfully identify the root cause.

Can you please help me with these details pertaining to your app? This will help me narrow down & mimic the app setup running into this issue.

Does your have multiple processes?
Does your app initialize Firebase using multiple Projects?

[quibi-jlk]

Thanks @ankitaj224. No to both questions, just one process and one firebase project.

[ankitaj224]

@quibi-jlk
Thanks for the quick response :)

Did you / other reporters notice any pattern about this issue happening only in specific Android Versions or devices?

[quibi-jlk]

As far as I can tell, it seems fairly aligned with our overall distribution in terms of manufacturer, os version, etc.

[fangor16]

For mine, got multiple projects.
As for crashes, 51% Android 10, 39% Android 9.
80% in background.

But for my app, the last crash was on 4th June 2020.
My app only has around 40k+ active users.

[ankitaj224]

@fangor16 Thanks for the stats. Do you have a bug report for the recent crashes from Google Play that we can take a look at?

[Vaisakhk]

@ankitaj224 My project also getting the same crash after the latest update

These are my dependencies

implementation "com.google.firebase:firebase-core:17.2.3"
implementation "com.google.firebase:firebase-messaging:20.1.1"
implementation "com.google.firebase:firebase-perf:19.0.5"
implementation 'com.google.firebase:firebase-auth:19.3.1'

Stack trace From Crashlytics

Fatal Exception: java.lang.IllegalStateException
at com.google.firebase.iid.FirebaseInstanceId.zzl(FirebaseInstanceId.java:78)
at com.google.firebase.iid.FirebaseInstanceId.getId(FirebaseInstanceId.java:3)
at com.google.firebase.perf.internal.zzf.zzbu(zzf.java:27)
at com.google.firebase.perf.internal.zzf.zzbt(zzf.java:73)
at com.google.firebase.perf.internal.zzf.zza(zzf.java)
at com.google.firebase.perf.internal.zze.run(zze.java:2)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
at java.lang.Thread.run(Thread.java:764)

[ankitaj224]

@Vaisakhk Thanks for reporting the issue and providing device/os stats. Do you have any context or bug reports for this crash? Or if you can paste the stack trace of all threads as seen in crashlytics, it would be helpful.

This crash could occur due to multiple reasons. As seen from @quibi-jlk stack trace : firebase_installations threads being stalled due to CPU load, eventually resulting in timeout and causing this crash. I was able to reproduce this particular case.

Other stack traces related to the same issue will help us identify if thread starvation is the main root cause for this crash.

[quibi-jlk]

@ankitaj224 given that a majority of these crashes are with the app in the background, I wonder if doze mode has something to do with this. Perhaps some background job isn't grabbing a wake lock during a maintenance window or something?

[ankitaj224]

@quibi-jlk That sounds like a possibility. Thanks for the suggestion 👍 , I ll test my app in Doze and Standby mode to see if I can reproduce this crash. I will keep you posted on how that test goes.

[szymone]

@ankitaj224 Any update on this issue? In our app this crash occures when Firebase getId() method is called from background thread, exactly when sync is called using Android accounts and auto sync feature. The app activity is not visible and app process is not started.

Caused by java.lang.InterruptedException
       at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1350)
       at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:278)
       at com.google.firebase.iid.FirebaseInstanceId.zzl(FirebaseInstanceId.java:64)
       at com.google.firebase.iid.FirebaseInstanceId.getId(FirebaseInstanceId.java:48)
       at pl.mapa_turystyczna.app.helpers.DeviceUtils.getDeviceId(DeviceUtils.java:13)
       at pl.mapa_turystyczna.app.analytics.AnalyticsService.<init>(AnalyticsService.java:87)
       at pl.mapa_turystyczna.app.analytics.AnalyticsService.getInstance(AnalyticsService.java:100)
       at pl.mapa_turystyczna.app.tracks.TracksSyncAdapter.onPerformSync(TracksSyncAdapter.java:151)
       at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:272)

[ankitaj224]

@szymone Thanks for reaching out. The stack trace you pasted doesn't look related to the IllegalStateException. I would request you to report a new issue and we can track what's going on in that issue.

[ankitaj224]

@quibi-jlk

Very sorry for slow response. I was caught up with other high priority tasks.

Based on our earlier discussion, I tested the app in doze & standby mode and that doesn't seem to be an issue. The FirebaseInstanceId.getId() worked as intended.

However, I was able to reproduce this issue due to thread starvation.

Are you/other developers reporting this crash are explicitly calling FirebaseInstanceId.getId() in their app?

The answer to the above question will help confirm my theory: In an app usually when Fireperf is enabled; Fireperf is the first service that requests FirebaseInstanceId.getId() which internally calls FirebaseInstallations.getId() with a 30s timeout. In CPU bound devices - background threads that generate/fetch the ID are being starved resulting in timeout & causing this crash.

As most of the stack traces are when Fireperf is calling getId, we are working with FirePerf team to improve the way getId() is invoked. That should most likely resolve this issue.

Fireperf is releasing a new version on July 16, 2020. I will update this thread once the new version is out.

Thanks for your patience on this issue.

[quibi-jlk]

Thanks, @ankitaj224, that's a super interesting theory and sounds plausible to me! We don't call FirebaseInstanceId.getId() a ton in our app (never in the background), but we do actually call it on occasion during normal app usage. We do use Firebase Perf, so this definitely sounds like a possible cause. Thanks for your persistence on this :-).

[ankitaj224]

com.google.firebase:firebase-perf:19.0.6

@fangor16 Though the stack trace you reported looks the same, the cause is different. Also, you are transitively using older version of firebase-installations:16.0.0 or firebase-iid:20.1.1 as noted in the stack trace you linked https://pastebin.com/UMkjvpZV.

Please try updating to the newer versions of perf, crashlytics and firebase-analytics and let us know if you are continuing to see the issue.

Thank you.

[szymone]

@ankitaj224 There are two threads, please check below.

Fatal Exception: java.lang.IllegalStateException: java.lang.InterruptedException
       at com.google.firebase.iid.FirebaseInstanceId.zzl(FirebaseInstanceId.java:73)
       at com.google.firebase.iid.FirebaseInstanceId.getId(FirebaseInstanceId.java:48)
       at pl.mapa_turystyczna.app.helpers.DeviceUtils.getDeviceId(DeviceUtils.java:13)
       at pl.mapa_turystyczna.app.analytics.AnalyticsService.<init>(AnalyticsService.java:87)
       at pl.mapa_turystyczna.app.analytics.AnalyticsService.getInstance(AnalyticsService.java:100)
       at pl.mapa_turystyczna.app.routes.RoutesSyncAdapter.onPerformSync(RoutesSyncAdapter.java:162)
       at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:272)

Caused by java.lang.InterruptedException
       at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1350)
       at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:278)
       at com.google.firebase.iid.FirebaseInstanceId.zzl(FirebaseInstanceId.java:64)
       at com.google.firebase.iid.FirebaseInstanceId.getId(FirebaseInstanceId.java:48)
       at pl.mapa_turystyczna.app.helpers.DeviceUtils.getDeviceId(DeviceUtils.java:13)
       at pl.mapa_turystyczna.app.analytics.AnalyticsService.<init>(AnalyticsService.java:87)
       at pl.mapa_turystyczna.app.analytics.AnalyticsService.getInstance(AnalyticsService.java:100)
       at pl.mapa_turystyczna.app.routes.RoutesSyncAdapter.onPerformSync(RoutesSyncAdapter.java:162)
       at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:272)

[ankitaj224]

@szymone The stack trace you posted doesn't seem related to this particular git issue. I would recommend reporting a new git issue. You can assign it to me and I will forward it to the right team.

FWIW, I did check the stack trace you linked with the FirebaseInstanceId team and doesn't look like they throw InterruptedException anywhere. Anyways, let's follow up on what's going on there.

Thanks.

[szymone]

@ankitaj224 Thanks for checking this out. Currently I'm not seeing this crash any more and it'd be hard to debug, so I won't report this for now. Thanks once again.

[ankitaj224]

For developers impacted by this issue, please try & update to the latest version of Fireperf - 19.0.8 released on July 17, 2020. The latest version contains a possible fix to the IllegalStateException.

Also, please report your findings on this issue after the Fireperf update.

[ankitaj224]

@quibi-jlk, @Vaisakhk : Have you tried updating to the latest version of Fireperf? Please drop a note if the issue persists.

[google-oss-bot]

Hey @quibi-jlk. We need more information to resolve this issue but there hasn't been an update in 5 weekdays. I'm marking the issue as stale and if there are no new updates in the next 5 days I will close it automatically.

If you have more information that will help us get to the bottom of this, just add a comment!

[quibi-jlk]

Hi @ankitaj224 thanks for the update! I haven't had a chance to try it out yet, but I'll get this update in our next release and try to collect some fresh data.

[ashwinraghav]

Please poke back/create a new issue if you continue seeing problems. Closing for now