Skip to content
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

When using suspending async/await, stacktrace contains no application code #3474

Open
ferinagy opened this issue Oct 5, 2020 · 12 comments · May be fixed by #3475
Open

When using suspending async/await, stacktrace contains no application code #3474

ferinagy opened this issue Oct 5, 2020 · 12 comments · May be fixed by #3475

Comments

@ferinagy
Copy link

ferinagy commented Oct 5, 2020

Can be reproduced by simple test:

  @Test fun await404() {
    val retrofit = Retrofit.Builder()
            .baseUrl(server.url("/"))
            .addConverterFactory(ToStringConverterFactory())
            .build()
    val example = retrofit.create(Service::class.java)

    server.enqueue(MockResponse().setResponseCode(404))

    try {
      runBlocking {
        val deferred = async { example.body()  }

        deferred.await()
      }
      fail()
    } catch (e: HttpException) {
      val writer = StringWriter()
      e.printStackTrace(PrintWriter(writer))

      val trace = writer.toString()

      assertThat("KotlinSuspendTest" in trace).isTrue()
      assertThat("await404" in trace).isTrue()
    }
  }

By default the stacktrace will look like:

retrofit2.HttpException: HTTP 404 Client Error
	at retrofit2.KotlinExtensions$await$2$2.onResponse(KotlinExtensions.kt:53)
	at retrofit2.OkHttpCall$1.onResponse(OkHttpCall.java:161)
	at okhttp3.RealCall$AsyncCall.execute(RealCall.java:174)
	at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

This is not very helpful, as we don't know which call caused the exception.

Attempt at fixing can be found in #3475, comments appreciated. That would lead to following trace:

retrofit2.HttpException: HTTP 404 Client Error
	(Coroutine boundary)
	at retrofit2.KotlinSuspendTest$await404$1$deferred$1.invokeSuspend(KotlinSuspendTest.kt:190)
Caused by: retrofit2.HttpException: HTTP 404 Client Error
	at retrofit2.KotlinExtensions$await$2$2.onResponse(KotlinExtensions.kt:53)
	at retrofit2.OkHttpCall$1.onResponse(OkHttpCall.java:161)
	at okhttp3.RealCall$AsyncCall.execute(RealCall.java:174)
	at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
@JakeWharton
Copy link
Member

Requires CopyableThrowable to move to stable first, unfortunately.

@ferinagy
Copy link
Author

That is unfortunate, I did not notice it still has @ExperimentalCoroutinesApi.

Is there anyway we could do this locally - like via some CallAdapter? Or do we need to fork + use CopyableThrowable?

Because right now, we are having crashes with stacktrace without any app code in our crash console with no way to find where they are coming from.

@GiridharaSPK

This comment has been minimized.

@nordfalk
Copy link

nordfalk commented Apr 26, 2021

Here is a 'small but ugly' workaround that I use:

    // workaround for https://github.com/square/retrofit/issues/3474 so that we can see the URL and where the stacktraces came from
    fun wrapToBeTraceable(throwable: Throwable): Throwable {
        if (throwable is HttpException) {
            return Exception("${throwable.response()}", throwable)
        }
        return throwable
    }

And then in all my catch blocks I invoke wrapToBeTraceable() in the exception
I still dont get the exact call site, but the stack trace will indicate which catch-block that wrapped the Exception, and that's much better than nothing.

And then I add it to the uncaught exceptions handlers as well

private fun setUncaughtCrashHandler() {
    val priorExceptionHandler = Thread.getDefaultUncaughtExceptionHandler()
    Thread.setDefaultUncaughtExceptionHandler { t, throwable ->
        // workaround for retrofit+coroutines that will not show the real original call stack trace
        val e = Logger.wrapToBeTraceable(throwable)   
        priorExceptionHandler?.uncaughtException(t, e)
    }
}

As I said its ugly, but I cant see any other options :-|

@Qdafengzi
Copy link

CopyableThrowable不幸的是,需要先稳定下来。

I change net request to coroutine , My code also happened , CoroutineExceptionHandler and try cach all can not solve , I am going to collapse

@Red7M
Copy link

Red7M commented Oct 5, 2021

This issue is still occurring on com.squareup.retrofit2:retrofit:2.9.0

Fatal Exception: retrofit2.HttpException: HTTP 422 Unprocessable Entity
at retrofit2.KotlinExtensions$await$2$2.onResponse(KotlinExtensions.kt:53)
at retrofit2.OkHttpCall$1.onResponse(OkHttpCall.java:161)
at okhttp3.RealCall$AsyncCall.execute(RealCall.java:174)
at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
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:929)

My stacktrace does not refer to any application code. Are there any workarounds?

@nordfalk
Copy link

nordfalk commented Oct 5, 2021

Yes @Red7M , you can surround all calls to retrofit in try/catch blocks.
And then you invoke wrapToBeTraceable() to get the real stack trace:
Like

            try {
                ... some call to retrofit
            } catch (notUseFullExteption: Exception) {
                val useFullExteption = Logger.wrapToBeTraceable(notUseFullExteption) 
                useFullExteption.printStackTrace()  // or whatever logging
            }

its ugly but the only way I can see to get at least some useful information.

@OneFiveFour
Copy link

Any updates on this? @JakeWharton
In our last release we have thousands of 502 errors and no way of finding out what call exactly caused them. Not blaiming Retrofit, just stating. I will try the workaround and hope for the best.

@JakeWharton
Copy link
Member

Use an OkHttp interceptor and look up the Invocation tag on the Request to attribute status codes back to functions.

Updates will be posted as comments or status changes on the issue.

@OneFiveFour
Copy link

Very nice, thank you! That was tremendously helpful :)

If anyone here has the same problem, here is our implementation of such an interceptor:

import com.google.firebase.crashlytics.FirebaseCrashlytics
import okhttp3.Interceptor
import okhttp3.Response
import retrofit2.HttpException
import retrofit2.Invocation
import timber.log.Timber

/**
 * This Interceptor will log unsuccessful http calls to crashlytics with a hint of the last calling method name.
 */
class InvocationInterceptor(private val additionalLog: String) : Interceptor {

    override fun intercept(chain: Interceptor.Chain): Response {

        val request = chain.request()
        val tag = request.tag(Invocation::class)
        val response = chain.proceed(request)

        if (!response.isSuccessful && tag != null){
            val clazz = tag.method().declaringClass.`package`?.name + tag.method().declaringClass.name
            val method = tag.method().name
            val arguments = tag.arguments()
            val responseCode = response.code
            val message = "+++ Unsuccessful HTTP Call [$responseCode]: $clazz.$method $arguments ($additionalLog)"

            Timber.e(message)
            FirebaseCrashlytics.getInstance().recordException(RuntimeException(message))
        }

        return response
    }

}

@warting
Copy link

warting commented Nov 16, 2023

Very nice, thank you! That was tremendously helpful :)

If anyone here has the same problem, here is our implementation of such an interceptor:

tag.arguments() may contain PII data and probably shouldn't be logged to firebase if you care about that. For us it was enough to take tag.method().toString() to get useful information about what triggered the request. And then we just sent it as a log so that it will be uploaded to Crashlytics only if a crash is logged.

It will log something like this:

Network request called from: public abstract java.lang.Object foo.bar.SomeClient.doNetworkRequest(java.lang.Double,kotlin.coroutines.Continuation)

class InvocationInterceptor : Interceptor {
    override fun intercept(chain: Interceptor.Chain): Response {
        val request = chain.request()
        request.tag(Invocation::class.java)?.let {
            val method = tag.method().toString()
            val message = "Network request called from: $method"
            FirebaseCrashlytics.getInstance().log(message)
        } ?: FirebaseCrashlytics.getInstance().recordException(RuntimeException("No Invocation tag found on request."))
        
        return chain.proceed(request)
    }
}

@asemalfaqeh
Copy link

To prevent the app from crashing, I incorporated the following code into the application that inherits from the base application class.

Thread.setDefaultUncaughtExceptionHandler { thread: Thread, throwable: Throwable ->
// Handle the uncaught exception, e.g., log it or report it
Log.d(TAG, "exceptionsHandler: ${throwable.message}")
}

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

9 participants