square / retrofit

A type-safe HTTP client for Android and the JVM
https://square.github.io/retrofit/
Apache License 2.0
43.09k stars 7.3k forks source link

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

Open ferinagy opened 4 years ago

ferinagy commented 4 years ago

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 https://github.com/square/retrofit/pull/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 commented 4 years ago

Requires CopyableThrowable to move to stable first, unfortunately.

ferinagy commented 4 years ago

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 commented 3 years ago

I have added wrong headers that caused me that HTTP 400 Bad request error.

removing the following worked .addHeader("Content-Encoding", "UTF-8") .header("Accept-Encoding", "identity")

  might help someone
nordfalk commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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 commented 11 months ago

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 commented 9 months ago

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}") }