Open nbransby opened 3 months ago
I couldn't figure out how to label this issue, so I've labeled it for a human to triage. Hang tight.
Not sure how the call was cancelled, looking at the logs quite some time passes before the exception is thrown:
2024-07-30 14:26:03,735 [78677736] INFO - STDOUT - calling firebase function
2024-07-30 15:02:04,619 [80838620] INFO - STDERR - com.google.firebase.functions.FirebaseFunctionsException: INTERNAL
2024-07-30 15:02:04,620 [80838621] INFO - STDERR - at com.google.firebase.functions.FirebaseFunctions$2.onFailure(FirebaseFunctions.java:377)
2024-07-30 15:02:04,620 [80838621] INFO - STDERR - at okhttp3.RealCall$AsyncCall.execute(RealCall.java:211)
2024-07-30 15:02:04,620 [80838621] INFO - STDERR - at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
2024-07-30 15:02:04,620 [80838621] INFO - STDERR - at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
2024-07-30 15:02:04,620 [80838621] INFO - STDERR - at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
2024-07-30 15:02:04,620 [80838621] INFO - STDERR - at java.base/java.lang.Thread.run(Thread.java:840)
2024-07-30 15:02:04,620 [80838621] INFO - STDERR - Caused by: java.io.IOException: Canceled
2024-07-30 15:02:04,620 [80838621] INFO - STDERR - at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:121)
2024-07-30 15:02:04,620 [80838621] INFO - STDERR - at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
2024-07-30 15:02:04,620 [80838621] INFO - STDERR - at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
2024-07-30 15:02:04,620 [80838621] INFO - STDERR - at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:257)
2024-07-30 15:02:04,620 [80838621] INFO - STDERR - at okhttp3.RealCall$AsyncCall.execute(RealCall.java:201)
2024-07-30 15:02:04,621 [80838622] INFO - STDERR - ... 4 more
Hi @nbransby, thank you for reaching out. Can you share how you were calling the function? and if possible the function code snippet itself? Thanks!
Hey @nbransby. 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!
I am calling it as per https://firebase.google.com/docs/functions/callable?authuser=0&gen=1st#kotlin+ktx_3 (actually using https://kotlinlang.org/api/kotlinx.coroutines/kotlinx-coroutines-play-services/kotlinx.coroutines.tasks/await.html to get the result)
My guess is that the device goes to sleep between the call (14:26) and the exception (15:02) which may be the cause of okhttp throwing the IOException
Thank you for the details @nbransby. The Firebase Function call
method does handle IOException failures by wrapping them in FirebaseFunctionsException and propagating them through the returned Task, which represents the result of the function call. Any code waiting for the result of the call method will receive this exception.
As for the INTERNAL
error, this could mean that your function is throwing an error. According to our documentation of handling errors in callable functions,
To ensure the client gets useful error details, return errors from a callable by throwing (or returning a Promise rejected with) an instance of functions.https.HttpsError. The error has a code attribute that can be one of the values listed at functions.https.HttpsError. The errors also have a string message, which defaults to an empty string. They can also have an optional details field with an arbitrary value. If an error other than HttpsError is thrown from your functions, your client instead receives an error with the message INTERNAL and the code internal
Can you check your function logs and see what's causing the issue? Your logs show that the exception occurs ~30mins after the Function call, which is longer than the maximum value of timeoutSeconds indicated on our docs with 540 or 9 minutes.
com.google.firebase.functions.FirebaseFunctions$2.onFailure(FirebaseFunctions.java:377)
Well we know what the INTERNAL error means in this case from looking at the code you referenced in your last message plus the line of the stacktrace above right? It means the IOException thrown is not a InterruptedIOException which we can also verify from the stacktrace - its a plain old IOException thrown by okhttp here:
Caused by: java.io.IOException: Canceled
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:121)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:257)
at okhttp3.RealCall$AsyncCall.execute(RealCall.java:201)
If you look at the okhttp source from the first line of the caused by exception stracktrace above, you can see the exception is thrown clientside and has nothing to do with the firebase function.
if (canceled) {
streamAllocation.release();
throw new IOException("Canceled");
}
and the only place canceled
is set to true is here:
So something's calling cancel and if you look at the places in okhttp it is called there are several reasons for that and I would conclude that is something the firebase code should handle gracefully - happy to create a PR to do that if it helps.
Thank you for clarification and additional details @nbransby. Handling IOException in onFailure makes more sense now. I’ll notify our engineers about this.
PRs are all welcome. We really appreciate developers who are sharing their feedback and contributions since this helps us improve our SDK. You can check our contribution guidelines to get started.
Does
IOException
need to be handled here? https://github.com/firebase/firebase-android-sdk/blob/main/firebase-functions/src/main/java/com/google/firebase/functions/FirebaseFunctions.java#L375