square / okhttp

Square’s meticulous HTTP client for the JVM, Android, and GraalVM.
https://square.github.io/okhttp/
Apache License 2.0
45.76k stars 9.15k forks source link

EOFException: source exhausted prematurely #2193

Closed hu9678 closed 8 years ago

hu9678 commented 8 years ago

I'm always getting java.io.EOFException: source exhausted prematurely when I try a request using OkHttp (2.x, 3.x).

OkHttpClient client = new OkHttpClient();
Request request = new Request.Builder()
    .url("http://www.ddanzi.com")
    .build();   
Response response = client.newCall(request).execute();
System.out.println(response.body().string().length());

output

java.io.EOFException: source exhausted prematurely
    at okio.InflaterSource.read(InflaterSource.java:82)
    at okio.GzipSource.read(GzipSource.java:80)
    at okio.Buffer.writeAll(Buffer.java:956)
    at okio.RealBufferedSource.readByteArray(RealBufferedSource.java:92)
    at okhttp3.ResponseBody.bytes(ResponseBody.java:83)
    at okhttp3.ResponseBody.string(ResponseBody.java:109)

But if I add an Accept-Encoding header to a request addHeader("Accept-Encoding", "gzip") there is no problem. Does anyone know why?

swankjesse commented 8 years ago

My guess is that the webserver on ddanzi.com is returning the content-length of the original response, not the content-length of the compressed response. It’s a bug in their webserver & you’ll need them to fix it.

Work-around with Content-Encoding: identity as a request header.

edenman commented 6 years ago

Hey team! My server guys just migrated us from one type of AppEngine server to another, and now my okhttp connections all fail with this error. I've isolated it to:

I hooked up Charles proxy and got the raw headers coming back on the response:

Server  nginx
Date    Thu, 16 Nov 2017 00:30:11 GMT
Content-Type    application/json; charset=UTF-8
Cache-Control   no-cache, no-store, must-revalidate
Content-Encoding        gzip
Expires 0
Pragma  no-cache
Vary    Accept-Encoding
X-Appengine-Log-Flush-Count     0
Via     1.1 google
Alt-Svc hq=":443"; ma=2592000; quic=51303431; quic=51303339; quic=51303338; quic=51303337; quic=51303335,quic=":443"; ma=2592000; v="41,39,38,37,35"
Transfer-Encoding       chunked

I'm entirely willing to support the "there's a bug in the webserver" hypothesis, but there's no Content-Length header on the response. Any other ideas of what could be wrong here? Or suggestions for how to investigate further? What would a test of this even look like...raw response bytes?

(for now, I'm just gonna turn off BODY logging, but I'd really like to have that capability added back, it's super helpful for debugging)

JakeWharton commented 6 years ago

Actually bytes+headers would be awesome since we could repro in a unit test, in theory. Do you have a payload that doesn't contain anything secret? Or can your server engs set up an example one that you can capture the raw bytes from?

On Wed, Nov 15, 2017, 7:43 PM Eric Denman notifications@github.com wrote:

Hey team! My server guys just migrated us from one type of AppEngine server to another, and now my okhttp connections all fail with this error. I've isolated it to: okhttp:3.9.0 and retrofit:2.3.0 HttpLoggingInterceptor with level BODY I hooked up Charles proxy and got the raw headers coming back on the response:

Server nginx Date Thu, 16 Nov 2017 00:30:11 GMT Content-Type application/json; charset=UTF-8 Cache-Control no-cache, no-store, must-revalidate Content-Encoding gzip Expires 0 Pragma no-cache Vary Accept-Encoding X-Appengine-Log-Flush-Count 0 Via 1.1 google Alt-Svc hq=":443"; ma=2592000; quic=51303431; quic=51303339; quic=51303338; quic=51303337; quic=51303335,quic=":443"; ma=2592000; v="41,39,38,37,35" Transfer-Encoding chunked

I'm entirely willing to support the "there's a bug in the webserver" hypothesis, but there's no Content-Length header on the response. Any other ideas of what could be wrong here? Or suggestions for how to investigate further? What would a test of this even look like...raw response bytes?

(for now, I'm just gonna turn off BODY logging, but I'd really like to have that capability added back, it's super helpful for debugging)

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/square/okhttp/issues/2193#issuecomment-344777662, or mute the thread https://github.com/notifications/unsubscribe-auth/AAEEETTdqR-YX4gjKfyW0A67n02h5JOvks5s24UVgaJpZM4G-MVs .

edenman commented 6 years ago

Request Headers:

Content-Type | application/json
X-Recharge-Device-Platform | android
X-Recharge-App-Version | 1.7.1
X-Recharge-Session-ID | my-secret-session-id
Host | my-server.appspot.com
Connection | Keep-Alive
Accept-Encoding | gzip
User-Agent | okhttp/3.9.0

Response headers:

Server | nginx
Date | Thu, 16 Nov 2017 18:33:24 GMT
Content-Type | application/json; charset=UTF-8
Cache-Control | no-cache, no-store, must-revalidate
Content-Encoding | gzip
Expires | 0
Pragma | no-cache
Vary | Accept-Encoding
X-Appengine-Log-Flush-Count | 0
Via | 1.1 google
Alt-Svc | hq=":443"; ma=2592000; quic=51303431; quic=51303339; quic=51303338; quic=51303337; quic=51303335,quic=":443"; ma=2592000; v="41,39,38,37,35"
Transfer-Encoding | chunked

Response (from the "Compressed" tab in Charles):

00000000  1f 8b 08 00 00 00 00 00 00 ff aa 56 ca 4c 51 b2              V LQ 
00000010  52 32 34 31 37 35 b3 34 36 33 33 55 d2 51 ca 4d   R24175 4633U Q M
00000020  2d 2e 4e 4c 4f 55 b2 52 0a c9 c8 2c 56 c8 2c 56   -.NLOU R   ,V ,V
00000030  48 54 28 49 2d 2e 51 80 4a 28 a4 e5 17 29 24 a6   HT(I-.Q J(   )$ 
00000040  e4 66 e6 15 eb 29 d5 02 00 00 00 ff ff             f   )    
edenman commented 6 years ago

(I could also grab the bytes in an interceptor or something, but my okio-fu is weak so you'd have to give me a code snippet)

swankjesse commented 6 years ago

I suspect going from a network interceptor to an application interceptor will fix this. Network interceptors see the compressed response.

edenman commented 6 years ago

I'm already using application interceptors:

    val loggingInterceptor = HttpLoggingInterceptor()
    loggingInterceptor.level = BODY
    return OkHttpClient.Builder()
        .addInterceptor(APIHeadersInterceptor(sessionIdPref))
        .addInterceptor(loggingInterceptor)
        .build()

where APIHeadersInterceptor looks like:

class APIHeadersInterceptor(
    private val sessionIdPref: StringPreference
) : Interceptor {

  override fun intercept(chain: Chain): Response {
    val originalRequest = chain.request()
    val newRequestBuilder = originalRequest.newBuilder()
    newRequestBuilder
        .header("Content-Type", "application/json")
        .header("X-My-Operation-System-Header", "android")
        .header("X-My-App-Version-Header", BuildConfig.VERSION_NAME)
    val sessionId = sessionIdPref.get()
    if (sessionId != null) {
      newRequestBuilder.header("X-My-Session-ID-Header", sessionId)
    }
    return chain.proceed(newRequestBuilder.build())
  }
}
edenman commented 6 years ago

Figured it out: the new version of app-engine gzips responses automatically, and we had a GzipMiddleware interceptor on our server that was causing responses to sometimes be double-gzipped. Wheeeee! I'm still not sure why HttpLoggingInterceptor had anything to do with this, but whatever, I'm moving on. Thanks for the responses, team!

ethanyuwang commented 6 years ago

I'm having the same problem. Here are the logged request and response:

request:

I/System.out: INFO: Sending request http://test.essaybot.com/msg/tag_search on Connection{test.essaybot.com:80, proxy=DIRECT@ hostAddress=test.essaybot.com/34.208.145.50:80 cipherSuite=none protocol=http/1.1}
I/System.out: Content-Type: application/x-www-form-urlencoded
I/System.out: Content-Length: 33
I/System.out: Host: test.essaybot.com
I/System.out: Connection: Keep-Alive
I/System.out: Accept-Encoding: gzip
I/System.out: User-Agent: okhttp/3.11.0

Response:

I/System.out: INFO: Received response for http://test.essaybot.com/msg/tag_search in 62.2ms
I/System.out: Cache-Control: no-cache
I/System.out: Content-Encoding: gzip
I/System.out: Content-Length: 139
I/System.out: Content-Type: application/json
I/System.out: Set-Cookie: PHP_SESSION=0Q4rZJplDjrUNB4ZbWAG; Path=/; Max-Age=2592000
I/System.out: Set-Cookie: VISITOR_ID=65xGr53M1xM0waK8; Path=/; Max-Age=31536000
I/System.out: Date: Wed, 29 Aug 2018 20:45:06 GMT
I/System.out: INFO: Received response body bytes: 
I/System.out:  [31, -117, 8, 0, 0, 0, 0, 0, 0, -1, 44, -51, 65, 10, -62, 64, 12, 5, -48, -85, 72, -42, 93, -72, -18, -50, -91, 103, 16, -111, -23, 52, -83, 31, 66, -90, 100, 50, -94, -120, 119, -105, 116, -70, 9, 47, -16, -109, -1, 37, 54, 123, 104, -95, -15, 60, -112, 113, 109, -30, 52, -34, -24, 50, -65, 88, -67, 25, -45, 16, 70, -34, 97, 30, 115, 49, -28, 20, -128, 9, -108, 107, 80, -33, 96, -1, -12, 12, 22, 100, 36, 57, 93, -43, 89, 4, 43, 107, -65, -34, -74, 61, 58, -49, -56, -114, -94, -31, 86, -35, -110, -32, -8, 54, -23, 20, 88, -95, 107, -81, 101, 115, -44, 99, -109, 92, -98, 69, 66, 21, -119, -18, -65, 63, 0, 0, 0, -1, -1] 
I/System.out:  With length: 139

Content-Length is the correct length for response body. What else could cause this? Our server works fine with the web and iOS ends