Skip to content

IllegalStateException in FirebaseInstanceId #1528

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
quibi-jlk opened this issue May 5, 2020 · 39 comments
Closed

IllegalStateException in FirebaseInstanceId #1528

quibi-jlk opened this issue May 5, 2020 · 39 comments
Assignees
Labels
firebase-installations Firebase Installations service needs-attention

Comments

@quibi-jlk
Copy link

[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 #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
Copy link
Contributor

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
Copy link
Contributor

andirayo commented May 5, 2020

@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
Copy link
Contributor

andirayo commented May 5, 2020

@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
Copy link
Author

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
Copy link
Contributor

ashwinraghav commented May 5, 2020

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

./gradlew :app:dependencies

@andirayo
Copy link
Contributor

andirayo commented May 5, 2020

@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
Copy link
Contributor

ramanpreetSinghKhinda commented May 6, 2020

FYI: Another dev reported this with the exact same stacktraces and line numbers in v20.1.5 of IID -> #1454 (comment)

@quibi-jlk
Copy link
Author

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
Copy link
Contributor

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

@quibi-jlk
Copy link
Author

Attaching file with all 40 threads @ankitaj224
allthreadsfirebase.log

@vkryachko
Copy link
Member

vkryachko commented May 12, 2020

@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
Copy link

fangor16 commented May 15, 2020

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
Copy link

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
Copy link
Author

@ankitaj224 do you have any updates here?

@visumickey
Copy link
Contributor

Another issue similar to this #1494 .

@ankitaj224
Copy link
Contributor

@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
Copy link
Contributor

@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
Copy link
Author

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

@ankitaj224
Copy link
Contributor

@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
Copy link
Author

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

@fangor16
Copy link

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
Copy link
Contributor

@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
Copy link

@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)

Screen Shot 2020-06-20 at 5 45 53 PM

@ankitaj224
Copy link
Contributor

@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
Copy link
Author

@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
Copy link
Contributor

@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
Copy link

szymone commented Jul 1, 2020

@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
Copy link
Contributor

@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
Copy link
Contributor

@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
Copy link
Author

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
Copy link
Contributor

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
Copy link

szymone commented Jul 1, 2020

@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
Copy link
Contributor

@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
Copy link

szymone commented Jul 14, 2020

@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
Copy link
Contributor

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
Copy link
Contributor

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

@google-oss-bot
Copy link
Contributor

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
Copy link
Author

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
Copy link
Contributor

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

@firebase firebase locked and limited conversation to collaborators Sep 10, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
firebase-installations Firebase Installations service needs-attention
Projects
None yet
Development

No branches or pull requests