Crash after calling task.getResult().getToken() - IllegalArgumentException: method POST must have a request body. #1540

grebulon · 2020-05-11T08:48:47Z

[READ] Step 1: Are you in the right place?

yes

[REQUIRED] Step 2: Describe your environment

Android Studio version: 3.6.1
Firebase Component: firebase-messaging
Component version: 20.1.7

[REQUIRED] Step 3: Describe the problem

Sometimes, after calling task.getResult().getToken() my app crashes with the following stack.
This happens occasionally, usually once a week. After that the app keeps crashing on startup and the only thing that stops it from crashing is to delete the cache from Android's app settings.
I suspect it has to do with caching of the token because after cleaning the cache will make the problem goes away (until the next cache refresh)

java.lang.IllegalArgumentException: method POST must have a request body.
com.android.okhttp.Request$Builder.method(Request.java:267)
com.android.okhttp.internal.huc.JavaApiConverter.createOkResponseForCacheGet(JavaApiConverter.java:216)
com.android.okhttp.internal.huc.CacheAdapter.get(CacheAdapter.java:53)
com.android.okhttp.internal.http.HttpEngine.sendRequest(HttpEngine.java:316)
com.android.okhttp.internal.huc.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:483)
com.android.okhttp.internal.huc.HttpURLConnectionImpl.connect(HttpURLConnectionImpl.java:135)
com.android.okhttp.internal.huc.HttpURLConnectionImpl.getOutputStream(HttpURLConnectionImpl.java:266)
com.android.okhttp.internal.huc.DelegatingHttpsURLConnection.getOutputStream(DelegatingHttpsURLConnection.java:219)
com.android.okhttp.internal.huc.HttpsURLConnectionImpl.getOutputStream(HttpsURLConnectionImpl.java:30)
com.google.firebase.installations.remote.FirebaseInstallationServiceClient.writeRequestBodyToOutputStream(com.google.firebase:firebase-installations@@16.3.0:208)
com.google.firebase.installations.remote.FirebaseInstallationServiceClient.writeGenerateAuthTokenRequestBodyToOutputStream(com.google.firebase:firebase-installations@@16.3.0:248)
com.google.firebase.installations.remote.FirebaseInstallationServiceClient.generateAuthToken(com.google.firebase:firebase-installations@@16.3.0:369)
com.google.firebase.installations.FirebaseInstallations.fetchAuthTokenFromServer(com.google.firebase:firebase-installations@@16.3.0:471)
com.google.firebase.installations.FirebaseInstallations.doNetworkCall(com.google.firebase:firebase-installations@@16.3.0:342)
com.google.firebase.installations.FirebaseInstallations.lambda$doRegistrationInternal$0(com.google.firebase:firebase-installations@@16.3.0:330)
com.google.firebase.installations.FirebaseInstallations$$Lambda$5.run(Unknown Source:4)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
java.lang.Thread.run(Thread.java:919)

Note that I'm using okhttp 3.12.10 - the latest version that supports Android 4.4 (API 19). In okhttp 4.0, the code that throws this error is gone.
Looking in the okhttp source code, it seems that the problem is just as the error message says: FirebaseInstallationServiceClient is posting with body == null. I'd look in FirebaseInstallationServiceClient.writeGenerateAuthTokenRequestBodyToOutputStream but the source code is not in this git repository.

In my various emails with Firebase support they hinted that some of the initialization options are missing (API key, Project ID, etc.) but I'm using the automatic initialization with the gradle plugin and google-services.json exactly as described in the docs. Furthermore, I validated that the info from google-services.json is merged into the apk's resources and that firebase is initialized properly (by calling FirebaseApp.initializeApp() which lead to a log stating: "FirebaseApp name [DEFAULT] already exists!"

Steps to reproduce:

First you need to compile with okhttp 3.12.10 (any 3.12.x will do)

dependencies {
  implementation("com.squareup.okhttp3:okhttp:3.12.10")
}

Then call task.getResult().getToken() as in the code below.
Run it for some time, probably several times every day for a week, and it will probably happen. I think this has to do with caching of the token because after this crashes, it will keep on crashing until you clear the cache.

Relevant Code:

FirebaseInstanceId.getInstance().getInstanceId().addOnCompleteListener(new OnCompleteListener<InstanceIdResult>() {
    @Override
    public void onComplete(@NonNull Task<InstanceIdResult> task) {
        if (!task.isSuccessful()) {
            return;
        }
        String token = task.getResult().getToken();
    }
});

The text was updated successfully, but these errors were encountered:

google-oss-bot · 2020-05-11T08:48:51Z

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 · 2020-05-11T16:55:03Z

@grebulon :
Thank you for reporting this!

It seems like the Firebase Installations's weekly #GenerateAuthToken call is triggering this issue.
We will look into this!

Question: What percentage of end-users is affected or are all affected?

FYI:

As a temporary fix for this you can downgrade firebase-messaging to v20.1.0 or before.
FirebaseInstallationServiceClient.writeGenerateAuthTokenRequestBodyToOutputStream is part of this repository:

firebase-android-sdk/firebase-installations/src/main/java/com/google/firebase/installations/remote/FirebaseInstallationServiceClient.java

Line 246 in 9eb88b1

private void writeGenerateAuthTokenRequestBodyToOutputStream(HttpURLConnection httpURLConnection)
Upon quick search I could find this Github issue of the OkHttp library that seems to still affect developers in 2019: method POST must have a request body. square/retrofit#854. But nevertheless there seems to be a weird behavior that we will look into.

ankitaj224 · 2020-05-11T23:54:55Z

@grebulon Thanks for all the details on reproducing this issue.

Have you enabled HttpResponseCaching in your app?

grebulon · 2020-05-12T08:05:58Z

@andirayo, this effects many users. I've had around to 500 of reports on this from my automated crash reporting code in the past 3 weeks. That's only from people who chose to report. I think that in the end it will affect ALL users.
I saw the reports on the retrofit issue, but it doesn't seem related to this issue.
I will downgrade to 20.1.0 and see if that helps.

@ankitaj224 HttpResponseCache is not enabled.
I first saw this crash while using firebase-messaging:20.1.2 on April 12. This was the first update to firebase that I did in a long time. Before that, I was using 11.0.4.

Thank you for looking into this.

ankitaj224 · 2020-05-13T02:06:54Z

@grebulon Are you able to reproduce this issue consistently ? And if there is a demo app, can you please share the link which I can use to test.

grebulon · 2020-05-13T13:05:01Z

@ankitaj224 Not consistently. But I have enough users to push an update and wait for the next cache invalidation (which usually happens on weekends) and see if this helps.
Do you think that it's enough to just disable the httpURLConnection cache?

ankitaj224 · 2020-05-14T22:04:43Z

@grebulon
Most likely. I am still reading about the Okhttp underlying caching in Android. Disabling the httpURLConnection cache along with explicit Cache-control should help. I am trying to reproduce the issue and try this fix.

Do you use initialize Okhttp client with a cache in your app?

grebulon · 2020-05-15T08:55:30Z

@ankitaj224 I don't do anything explicit with the connection cache, so it must be using the default state.
I downgraded as andirayo suggested to v20.0 in my beta group and haven't seen any crashes from there.
But there's something that may be troubling - I have a debug report call in my code that I trigger when FirebaseMessagingService#onNewToken() is called and I haven't seen this happen even once for any of my users. I also trigger a report when a token changes after calling task.getResult().getToken() - which happens but very rarely.
What's the lifetime of these tokens? How often do they change?

andirayo · 2020-05-17T19:05:53Z

FCM registration tokens are constant for the lifetime of installations of your application, unless FCM has a reason to update the tokens.
Thus, not getting reports about tokens changing is nothing to worry about.

Question: Did this behavior change for you?

grebulon · 2020-05-18T06:00:37Z

That's OK as I'm not seeing tokens being replaced, and I'm not getting any more of the crashes after downgrading.
Drop me a note after releasing the caching change, and I'll test it on my beta group.

ankitaj224 · 2020-06-17T01:02:24Z

@grebulon firebase-messaging: 20.2.1 will be released by this week (June 19 2020) that should contain caching fix. Please try releasing the app with the latest version and let me know if it fixes the issue.

Thank you for testing out the fix.

google-oss-bot · 2020-06-25T01:01:09Z

Hey @grebulon. 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!

grebulon · 2020-06-25T09:58:55Z

Just to let you know that I can't do the test right now, but I'm on it and will test as soon as my release timeline has a free slot.

ankitaj224 · 2020-06-25T19:25:58Z

Thanks @grebulon . Looking forward to hearing how the tests go.

google-oss-bot · 2020-07-02T01:01:06Z

Hey @grebulon. 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!

grebulon · 2020-07-02T09:26:29Z

Hello Ankita (and googlebot)
I've deployed a beta of our app to a group of ~600 people and already got ~40 token change event notices so it seems to be working fine. But I'd give it another week or two to make sure that everything is fine.

ankitaj224 · 2020-07-06T17:36:06Z

@grebulon Thanks for the information. Keep us posted on your beta release results.

grebulon · 2020-07-12T08:27:27Z

I think it's safe to say that this bug is fixed. I'm still running the new version in a beta group of a few hundreds and if there's another problem I will report. Thank you for handling this so professionally.

ankitaj224 · 2020-07-13T21:22:45Z

Thanks for the confirmation @grebulon . I will go ahead and close this issue for now. Please feel free to reopen if you continue to see the issue.

google-oss-bot added the needs-triage label May 11, 2020

andirayo added firebase-installations Firebase Installations service and removed needs-triage labels May 11, 2020

andirayo assigned andirayo and ankitaj224 May 11, 2020

ankitaj224 mentioned this issue May 12, 2020

Disable FIS network calls to use cached response. #1555

Merged

ashwinraghav added needs-attention and removed needs-attention labels Jun 3, 2020

ankitaj224 added needs-info and removed needs-attention labels Jun 24, 2020

google-oss-bot added the no-recent-activity label Jun 25, 2020

google-oss-bot added needs-attention and removed no-recent-activity needs-info labels Jun 25, 2020

ankitaj224 removed the needs-attention label Jun 25, 2020

ashwinraghav added the needs-info label Jun 30, 2020

google-oss-bot added the no-recent-activity label Jul 2, 2020

google-oss-bot added needs-attention and removed needs-info no-recent-activity labels Jul 2, 2020

ankitaj224 added needs-info and removed needs-attention labels Jul 6, 2020

google-oss-bot added needs-attention and removed needs-info labels Jul 12, 2020

ankitaj224 closed this as completed Jul 13, 2020

firebase locked and limited conversation to collaborators Aug 13, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Crash after calling task.getResult().getToken() - IllegalArgumentException: method POST must have a request body. #1540

Crash after calling task.getResult().getToken() - IllegalArgumentException: method POST must have a request body. #1540

grebulon commented May 11, 2020 •

edited

Loading

google-oss-bot commented May 11, 2020

andirayo commented May 11, 2020

ankitaj224 commented May 11, 2020

grebulon commented May 12, 2020 •

edited

Loading

ankitaj224 commented May 13, 2020

grebulon commented May 13, 2020

ankitaj224 commented May 14, 2020

grebulon commented May 15, 2020 •

edited

Loading

andirayo commented May 17, 2020

grebulon commented May 18, 2020

ankitaj224 commented Jun 17, 2020

google-oss-bot commented Jun 25, 2020

grebulon commented Jun 25, 2020

ankitaj224 commented Jun 25, 2020

google-oss-bot commented Jul 2, 2020

grebulon commented Jul 2, 2020

ankitaj224 commented Jul 6, 2020

grebulon commented Jul 12, 2020

ankitaj224 commented Jul 13, 2020

Crash after calling task.getResult().getToken() - IllegalArgumentException: method POST must have a request body. #1540

Crash after calling task.getResult().getToken() - IllegalArgumentException: method POST must have a request body. #1540

Comments

grebulon commented May 11, 2020 • edited Loading

[READ] Step 1: Are you in the right place?

[REQUIRED] Step 2: Describe your environment

[REQUIRED] Step 3: Describe the problem

Steps to reproduce:

Relevant Code:

google-oss-bot commented May 11, 2020

andirayo commented May 11, 2020

ankitaj224 commented May 11, 2020

grebulon commented May 12, 2020 • edited Loading

ankitaj224 commented May 13, 2020

grebulon commented May 13, 2020

ankitaj224 commented May 14, 2020

grebulon commented May 15, 2020 • edited Loading

andirayo commented May 17, 2020

grebulon commented May 18, 2020

ankitaj224 commented Jun 17, 2020

google-oss-bot commented Jun 25, 2020

grebulon commented Jun 25, 2020

ankitaj224 commented Jun 25, 2020

google-oss-bot commented Jul 2, 2020

grebulon commented Jul 2, 2020

ankitaj224 commented Jul 6, 2020

grebulon commented Jul 12, 2020

ankitaj224 commented Jul 13, 2020

grebulon commented May 11, 2020 •

edited

Loading

grebulon commented May 12, 2020 •

edited

Loading

grebulon commented May 15, 2020 •

edited

Loading