retrofit icon indicating copy to clipboard operation
retrofit copied to clipboard

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

Open ferinagy opened this issue 4 years ago • 12 comments

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)

ferinagy avatar Oct 05 '20 13:10 ferinagy

Requires CopyableThrowable to move to stable first, unfortunately.

JakeWharton avatar Oct 16 '20 13:10 JakeWharton

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.

ferinagy avatar Oct 16 '20 22:10 ferinagy

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
  

GiridharaSPK avatar Feb 05 '21 07:02 GiridharaSPK

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 :-|

nordfalk avatar Apr 26 '21 08:04 nordfalk

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

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

Qdafengzi avatar May 13 '21 07:05 Qdafengzi

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?

Red7M avatar Oct 05 '21 16:10 Red7M

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.

nordfalk avatar Oct 05 '21 17:10 nordfalk

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.

OneFiveFour avatar Feb 04 '23 13:02 OneFiveFour

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.

JakeWharton avatar Feb 04 '23 18:02 JakeWharton

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
    }

}

OneFiveFour avatar Feb 13 '23 09:02 OneFiveFour

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

warting avatar Nov 16 '23 07:11 warting

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

asemalfaqeh avatar Jan 19 '24 12:01 asemalfaqeh