ChuckerInterceptor fetches the whole body even if the application isn't doing so

[oakkitten]

Simply plugging in ChuckerInterceptor causes the whole response body to be read, even if the application isn't reading the whole of it. Not only this is a very unwanted side effect, this can also crash the app. This is an example crash while trying to (not) read a ~50MB file:

2020-03-04 22:49:34.915 8061-8119 E/AndroidRuntime: FATAL EXCEPTION: OkHttp Dispatcher
    Process: process, PID: 8061
    java.lang.OutOfMemoryError: Failed to allocate a 102720552 byte allocation with 25165824 free bytes and 31MB until OOM, target footprint 260095632, growth limit 268435456
        at java.lang.StringFactory.newStringFromBytes(StringFactory.java:225)
        at java.lang.StringFactory.newStringFromBytes(StringFactory.java:249)
        at okio.Buffer.readString(Buffer.kt:306)
        at okio.Buffer.readString(Buffer.kt:295)
        at com.chuckerteam.chucker.api.ChuckerInterceptor.processResponseBody(ChuckerInterceptor.kt:159)
        at com.chuckerteam.chucker.api.ChuckerInterceptor.processResponse(ChuckerInterceptor.kt:133)
        at com.chuckerteam.chucker.api.ChuckerInterceptor.intercept(ChuckerInterceptor.kt:65)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:100)
        at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:197)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:502)
        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:919)

you can reproduce this by starting a fake web server and looking at how much it sends (and observing the crash):

cat /dev/urandom > file
{ echo -ne "HTTP/1.0 200 OK\r\nContent-Length: $(wc -c <file)\r\n\r\n"; cat file } | pv | nc -l 8080

It is my impression that the interceptor should only observe the doings of the application and should report either what the application reads or what the device receives.

P.S. setting maxContentLength in ChuckerInterceptor() seems to have no effect

[vbuberen]

Thanks for reporting this issue.

How do you use Chucker? As a network or application interceptor?

As to you suggestion on observing only what application does - could you elaborate more on this?
I am not sure I understand how do we know if the app consumes the whole response or not by being in the interceptors level?

[oakkitten]

I'm using it as an application interceptor. I can't use it as a network interceptor due to issue #242.

I am not sure I understand how do we know if the app consumes the whole response or not by being in the interceptors level?

I'm not really familiar with the internals of OkHttp or Chucker so I don't know if it can be easily done. But it seems that Chucker is already returning a copy of the Response, so, barring the lack of more proper interception methods, why not return a modified response that monitors the data the application receives? For instance, you could return a modified InputStream from Response.body().byteStream() that records whatever it reads.

At the very least, I'd like to have an option to not read the body at all. This would be preferable to having any side effects.

P.S. Android Studio's profiler seems to be able to inspect http requests as well. Perhaps there's an API for that?

[vbuberen]

I am still not sure that I understood your idea.
@cortinico @MiSikora probably, you could help here?

[MiSikora]

If I understand it correctly it is more or less like the idea I mentioned some time ago about streaming simultaneously to the end user and a file. We would need an implementation of Source that is capable of streaming to two consumers at once. Basically Tee operator. Or a cache-like mechanism from OkHttp.

It is my impression that the interceptor should only observe the doings of the application and should report either what the application reads or what the device receives.

I disagree, however, about this point. I think if Chucker is applied as an application interceptor it makes sense. But if it is applied as a network interceptor then it should observe all the traffic regardless of the end consumer because they are interested in the network traffic.

[oakkitten]

What I'm trying to say is, if there's a 5 MB picture on the server, and an application that uses OkHttp explicitly reads 3 MB of it, and 4 MB is actually transferred between the client and the server (due to the library or OS buffering), the observer should be reporting either 3 MB or 4 MB.

What Chucker is doing, it's reading the whole file from the server and reporting 5 MB.

[oakkitten]

this seems to work, thanks!

one thought, though. it would be nice to be able to see the transferred amount, e.g. Response size: 5MiB, Transferred: 100KiB. currently Chucker reports the same Response size and Total size regardless of how much was transferred.

these numbers are also often stuck at -1 B, i'm assuming when Content-Length is missing. perhaps have Chucker say something along “no Content-Length” or “variable” instead of -1? also, Total size probably should be a real number.

it would be nice to have the transferred amount in the request list as well.

[MiSikora]

There is #209 tracking wrong size of responses. It should be super easy to fix now with streaming approach. Progressive reports should also be doable and not that complex. The problem is showing 100KiB out of 5MiB as the upper bound is sometimes not know due to missing Content-Length.

[oakkitten]

other applications such as browsers are often showing something along 100KiB out of ?

also, i'm encountering the following exception only when i'm using Chucker:

2020-03-25 20:13:42.309 I/Glide: Root cause (1 of 1)
    java.io.EOFException: source exhausted prematurely
        at okio.InflaterSource.read(InflaterSource.kt:75)
        at okio.GzipSource.read(GzipSource.kt:69)
        at okio.Buffer.writeAll(Buffer.kt:1655)
        at com.chuckerteam.chucker.api.ChuckerInterceptor$ChuckerTransactionTeeCallback.readResponseBuffer(ChuckerInterceptor.kt:264)
        at com.chuckerteam.chucker.api.ChuckerInterceptor$ChuckerTransactionTeeCallback.onSuccess(ChuckerInterceptor.kt:245)
        at com.chuckerteam.chucker.internal.support.TeeSource.close(TeeSource.kt:64)
        at okio.RealBufferedSource.close(RealBufferedSource.kt:498)
        at okio.RealBufferedSource.close(RealBufferedSource.kt:498)
        at okio.InflaterSource.close(InflaterSource.kt:118)
        at okio.GzipSource.close(GzipSource.kt:171)
        at okio.RealBufferedSource.close(RealBufferedSource.kt:498)
        at okio.RealBufferedSource$inputStream$1.close(RealBufferedSource.kt:170)
        at java.io.FilterInputStream.close(FilterInputStream.java:181)
        at com.ubergeek42.WeechatAndroid.utils.Utils.readInputStream(Utils.java:191)

this probably shouldn't be happening? readInputStream() reads as much data as it needs and simply closes the stream after.

[MiSikora]

Could you show readInputStream() method or at least how it read bytes? I want to replicate this behaviour in a test.

[oakkitten]

i probably should put try ... catch around the closing call

https://github.com/ubergeek42/weechat-android/blob/37bf333d780a66684fa698766a8cc14ea320ec7a/app/src/main/java/com/ubergeek42/WeechatAndroid/utils/Utils.java#L177-L190

[MiSikora]

What is happening is that the trailer bytes of the compressed stream are missing because you read only part of the stream and we save it as such to a file. So when we try to close the file that is being used to read original bytes it fails because the source is exhausted without expected bytes. I didn't predict such a use case. I need to consider what is the best way to solve it. Could you report it as a separate issue and link to our conversation?