With HttpCache enabled, adding an Interceptor causes ApolloNetworkException

[mrea1]

Summary
It seems this is related to #1786. On a fresh install with OkHttpClient:

OkHttpClient.Builder().apply {
     addInterceptor(HttpLoggingInterceptor().setLevel(HttpLoggingInterceptor.Level.BODY))
}

If a request does not have a cached response yet, this error is thrown

com.apollographql.apollo.exception.ApolloNetworkException: Failed to execute http call
        at com.apollographql.apollo.internal.interceptor.ApolloServerInterceptor$executeHttpCall$1.onFailure(ApolloServerInterceptor.kt:103)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:532)
        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:764)
     Caused by: java.io.IOException: canceled due to java.lang.IllegalStateException: closed
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:530)
        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:764)     	Suppressed: java.lang.IllegalStateException: closed
        at okio.RealBufferedSource.read(RealBufferedSource.kt:185)
        at com.apollographql.apollo.cache.http.ResponseBodyProxy$ProxySource.read(ResponseBodyProxy.java:75)

Version
2.5.3

Description

Full stack trace:

com.apollographql.apollo.exception.ApolloNetworkException: Failed to execute http call
        at com.apollographql.apollo.internal.interceptor.ApolloServerInterceptor$executeHttpCall$1.onFailure(ApolloServerInterceptor.kt:103)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:532)
        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:764)
     Caused by: java.io.IOException: canceled due to java.lang.IllegalStateException: closed
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:530)
        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:764)     	Suppressed: java.lang.IllegalStateException: closed
        at okio.RealBufferedSource.read(RealBufferedSource.kt:185)
        at com.apollographql.apollo.cache.http.ResponseBodyProxy$ProxySource.read(ResponseBodyProxy.java:75)
        at okio.RealBufferedSource.request(RealBufferedSource.kt:206)
        at okhttp3.logging.HttpLoggingInterceptor.intercept(HttpLoggingInterceptor.kt:247)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:517)

Note that I am also seeing a related(?) issue with the following interceptor:

class OAuthInterceptor(
    private val restRequestHelper: RestRequestHelper,
    private val sessionRepository: SessionRepository
) : Interceptor {

    override fun intercept(chain: Interceptor.Chain): Response {
        val newRequest = chain.request().newBuilder()
            .addHeader("Authorization", restRequestHelper.getAuthorizationHeader(sessionRepository.accessToken))
            .addHeader("User-Agent", restRequestHelper.getHeaderUserAgentString())
            .build()

        return chain.proceed(newRequest)
    }
}

    com.apollographql.apollo.exception.ApolloNetworkException: Failed to execute http call
        at com.apollographql.apollo.internal.interceptor.ApolloServerInterceptor$executeHttpCall$1.onFailure(ApolloServerInterceptor.kt:103)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:525)
        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:764)
     Caused by: okhttp3.internal.http2.StreamResetException: stream was reset: INTERNAL_ERROR
        at okhttp3.internal.http2.Http2Stream.takeHeaders(Http2Stream.kt:148)
        at okhttp3.internal.http2.Http2ExchangeCodec.readResponseHeaders(Http2ExchangeCodec.kt:96)
        at okhttp3.internal.connection.Exchange.readResponseHeaders(Exchange.kt:106)
        at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.kt:79)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:34)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at com.apollographql.apollo.cache.http.HttpCacheInterceptor.networkFirst(HttpCacheInterceptor.java:89)
        at com.apollographql.apollo.cache.http.HttpCacheInterceptor.intercept(HttpCacheInterceptor.java:51)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at okhttp3.logging.HttpLoggingInterceptor.intercept(HttpLoggingInterceptor.kt:221)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at com.doximity.doximitydroid.sources.auth.OAuthInterceptor.intercept(OAuthInterceptor.kt:18)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at com.apollographql.apollo.ApolloClientAwarenessInterceptor.intercept(ApolloClientAwarenessInterceptor.kt:18)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:517)
        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:764) 

[martinbonnin]

Hi 👋

Is there any chance you can share a reproducer project somewhere ? I tried adding a HTTP cache and interceptor to the tutorial: https://github.com/apollographql/apollo-android-tutorial/tree/reproducer-2912
But haven't been able to reproduce so far.

[mrea1]

@martinbonnin I figured out the problem - we had a duplicate HttpLoggingInterceptor set on our OkHttpClient. If I remove the duplicate, http caching works fine. We have a number of different OkHttpClients that build off of a "base" OkHttpClient. In one case, both the base client and a "sub" client were adding a HttpLoggingInterceptor, resulting in a total of 2

So I'm not sure if this is an Apollo issue or not? Seems like it should be able to handle this case potentially

I looked at your reproducer-2912 branch on the tutorial repo. I don't have access to push up, but if you add a second HttpLoggingInterceptor here, you'll see a IllegalStateException: closed like I posted in the issue description

In any case, thank you for the quick response!

[martinbonnin]

Thanks for the follow up! If that's ok with you I'll close this issue as having 2 HttpLoggingInterceptor sounds like a edge case? We can always reopen if that happens in other cases.

[mrea1]

Sounds good to me, thanks @martinbonnin