Search code examples
kotlinretrofitokhttp

Retrofit OkHttp - "unexpected end of stream"

I am getting "Unexpected end of stream" while using Retrofit (2.9.0) with OkHttp3 (4.9.1)

Retrofit configuration:

interface ApiServiceInterface {

    companion object Factory{

        fun create(): ApiServiceInterface {
            val interceptor = HttpLoggingInterceptor()
            interceptor.level = HttpLoggingInterceptor.Level.BODY

            val client = OkHttpClient.Builder()
                .connectTimeout(30, TimeUnit.SECONDS)
                .writeTimeout(30, TimeUnit.SECONDS)
                .readTimeout(30,TimeUnit.SECONDS)
                .addInterceptor(Interceptor { chain ->
                    chain.request().newBuilder()
                        .addHeader("Connection", "close")
                        .addHeader("Accept-Encoding", "identity")
                        .build()
                        .let(chain::proceed)
                })
                .retryOnConnectionFailure(true)
                .connectionPool(ConnectionPool(0, 5, TimeUnit.MINUTES))
                .protocols(listOf(Protocol.HTTP_1_1))
                .build()
            val gson = GsonBuilder().setLenient().create()
            val retrofit = Retrofit.Builder()
                    .addCallAdapterFactory(CoroutineCallAdapterFactory())
                    .addConverterFactory(GsonConverterFactory.create(gson))
                    .baseUrl("http://***.***.***.***:****")
                    .client(client)
                    .build()
            return retrofit.create(ApiServiceInterface::class.java)
        }
    }


    @Headers("Content-type: application/json", "Connection: close", "Accept-Encoding: identity")
    @POST("/")
    fun requestAsync(@Body data: JsonObject): Deferred<Response>
}

So far I have found out the following:

  1. This issue only occurs for me while using Android Studio emulators running from Windows series OS (7, 10, 11) - this was reproduced on 2 different laptops from different networks.
  2. If running Android Studio emulators under OS X the issue won't reproduce in 100% cases.
  3. ARC/Postman clients never has any issues completing same requests to my backend.
  4. On running from Windows Android Studio emulators this issue reproduces in about 10-50% requests, other requests work without problem.
  5. The identical requests can result in this error or complete sucessfully.
  6. Responses which take about 11 sec to complete can result in success, while responses which take about 100 msec to complete can result in this error.
  7. Commenting off .client(client) from retrofit configuration eliminates this issue, but I loose the opportunity to use interceptors and other OkHttp functionality.
  8. Adding headers (Connection: close, Accept-Encoding: identity) does not solve issue.
  9. Turning retryOnConnectionFailure on or off has no impact on issue as well.
  10. Changing HttpLoggingInterceptor level or removing it completely does not solve issue.

Server-side configuration:

const http = require('http');
const server = http.createServer((req, res) => {

    const callback = function(code, request, data) {
        let result = responser(code, request, data);
        res.writeHead(200, {
            'Content-Type' : 'x-application/json',
            'Connection': 'close',
            'Content-Length': Buffer.byteLength(result)
        });
        res.end(result);
    };

    ...
}

server.listen(process.env.PORT, process.env.HOSTNAME, () => {
    console.log(`Server is running`);
});

So, based on 1,2,3 - this is unlikely server-side issue.
Based on 4, 5, 6 - it is not malformed request related or execution time related issue. Guessing from 7 - this issue roots lay in OkHttp rather than Retrofit itself.

I have read almost half of stackoverflow is search of resolution, like:
unexpected end of stream retrofit
Retrofit OkHttp unexpected end of stream on Connection error
and also discussion at OkHttp on Github:
https://github.com/square/okhttp/issues/3682
https://github.com/square/okhttp/issues/3715
But nothing helped so far.

Any idea what might be causing the problem?

Update

I've got more info on situation.

First, I changed headers on backend to not to pass Content-Length and pass Transfer-Encoding : identity instead. I don't know why, but Postman gives an error if theese headers are present both, saying it is not right.

res.writeHead(200, {
            'Content-Type' : 'x-application/json',
            'Connection': 'close',
            'Transfer-Encoding': 'identity'
        });

After that I started to receive another error on Windows hosted Android Studio emulators (with equal ratio of fail / success to "Unexpected end of stream")

2021-12-09 14:58:19.696 401-401/? D/P2P-> FRG DEBUG:: java.io.EOFException: End of input at line 1 column 1807 path $.meta
        at com.google.gson.stream.JsonReader.nextNonWhitespace(JsonReader.java:1397)
        at com.google.gson.stream.JsonReader.doPeek(JsonReader.java:483)
        at com.google.gson.stream.JsonReader.hasNext(JsonReader.java:415)
        at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$Adapter.read(ReflectiveTypeAdapterFactory.java:216)
        at retrofit2.converter.gson.GsonResponseBodyConverter.convert(GsonResponseBodyConverter.java:40)
        at retrofit2.converter.gson.GsonResponseBodyConverter.convert(GsonResponseBodyConverter.java:27)
        at retrofit2.OkHttpCall.parseResponse(OkHttpCall.java:243)
        at retrofit2.OkHttpCall$1.onResponse(OkHttpCall.java:153)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:519)
        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)

Spending a lot of time debugging this issue I have found that this exception was generated by JsonReader.java in method nextNonWhitespace where it try to to get colons, double quotes and curly or square braces to compose json object from decoded as char array buffer.

This buffer itself is received in fillBuffer method of the same module and it has length limit of 1024 elements. In my case the backend response is longer that this value (1807 chars), so while JsonReader.java parses my response as json object it do this in 2 iterations.

Each iteration it fills the buffer here:

int total;
while ((total = in.read(buffer, limit, buffer.length - limit)) != -1) {
    limit += total;

    // if this is the first read, consume an optional byte order mark (BOM) if it exists
    if (lineNumber == 0 && lineStart == 0 && limit > 0 && buffer[0] == '\ufeff') {
        pos++;
        lineStart++;
        minimum++;
    }

    if (limit >= minimum) {
        return true;
    }
}

the read method is called on ResponseBody.kt class from okhttp3

@Throws(IOException::class)
    override fun read(cbuf: CharArray, off: Int, len: Int): Int {
      if (closed) throw IOException("Stream closed")

      val finalDelegate = delegate ?: InputStreamReader(
          source.inputStream(),
          source.readBomAsCharset(charset)).also {
        delegate = it
      }
      return finalDelegate.read(cbuf, off, len)
    }

The main problem is:

At first iteration all goes well, ResponseBody.kt "reads" first 1024 chars and gives them to JsonReader.java where it composes a part of response object.

1st iteration

When second iteration comes ResponseBody.kt "reads" the last part of response and fills with it the start of char buffer, so char buffer now contains as its first elements the tail of response, and after that - all elements which was left there after firts iteration.

The main problem is that it im most cases (about 80%) looses last char from response, in about 10% in looses 2 last chars from response and in about 10% it reads all chars. Here is shots:

Wrong number of chars It must contains 783 chars to complete json, but as shown at line 1290 it receives only 782.

Looking at buffer itself Wrong buffer
the char at 782 index (783 in order) must be second curly brace that closes json root, but instead of it there are leftovers from first iteration started. This results in exception mentioned above.

Now if we look at situation where requests finished successfully: Good number of chars With the same request it occasionly returns valid number of chars: 783

And the buffer itself is: enter image description here Now the second brace is present where it must be.

In this case request will be successfull.

The same response ending from Postman: postman The Postman success rate in parsing response is 100%, the same is true for OS X hosted android studio emulators and real devices I've used.

Update 2

It seems full buffer obtained in RealBufferedSource.kt:

internal inline fun RealBufferedSource.commonSelect(options: Options): Int {
  check(!closed) { "closed" }

  while (true) {
    val index = buffer.selectPrefix(options, selectTruncated = true)
    when (index) {
      -1 -> {
        return -1
      }
      -2 -> {
        // We need to grow the buffer. Do that, then try it all again.
        if (source.read(buffer, Segment.SIZE.toLong()) == -1L) return -1
      }
      else -> {
        // We matched a full byte string: consume it and return it.
        val selectedSize = options.byteStrings[index].size
        buffer.skip(selectedSize.toLong())
        return index
      }
    }
  }
}

and here it is already missing last char: enter image description here

Update 3

Found this unsolved question which is exactly the same behavior:
Retrofit Json data truncated
Also comment from Android Studio emulators issues tracker:
https://issuetracker.google.com/issues/119027639#comment9

Solution

  • OK, It took some time, but I've found what was going wrong and how to workaround that.

    When Android Studio's emulators running in Windows series OS (checked for 7 & 10) receive json-typed reply from server with retrofit it can with various probability loose 1 or 2 last symbols of the body when it is decoded to string, this symbols contain closing curly brackets and so such body could not be parsed to object by gson converter which results in throwing exception.

    The idea of workaround I found is to add an interceptor to retrofit which would check the decoded to string body if its last symbols match those of valid json response and add them if they are missed.

    interface ApiServiceInterface {

    companion object Factory{

        fun create(): ApiServiceInterface {
            val interceptor = HttpLoggingInterceptor()
            interceptor.level = HttpLoggingInterceptor.Level.BODY
            
            val stringInterceptor = Interceptor { chain: Interceptor.Chain ->
                val request = chain.request()
                val response = chain.proceed(request)
                val source = response.body()?.source()
                source?.request(Long.MAX_VALUE)
                val buffer = source?.buffer()
                var responseString = buffer?.clone()?.readString(Charset.forName("UTF-8"))
                if (responseString != null && responseString.length > 2) {
                    val lastTwo = responseString.takeLast(2)
                    if (lastTwo != "}}") {
                        val lastOne = responseString.takeLast(1)
                        responseString = if (lastOne != "}") {
                            "$responseString}}"
                        } else {
                            "$responseString}"
                        }
                    }
                }
                val contentType = response.body()?.contentType()
                val body = ResponseBody.create(contentType, responseString ?: "")
                return@Interceptor response.newBuilder().body(body).build()
            }

            val client = OkHttpClient.Builder()
                .connectTimeout(30, TimeUnit.SECONDS)
                .writeTimeout(30, TimeUnit.SECONDS)
                .readTimeout(30,TimeUnit.SECONDS)
                .addInterceptor(interceptor)
                .addInterceptor(stringInterceptor)
                .retryOnConnectionFailure(true)
                .connectionPool(ConnectionPool(0, 5, TimeUnit.MINUTES))
                .protocols(listOf(Protocol.HTTP_1_1))
                .build()
            val gson = GsonBuilder().create()
            val retrofit = Retrofit.Builder()
                .addCallAdapterFactory(CoroutineCallAdapterFactory())
                .addConverterFactory(GsonConverterFactory.create(gson))
                .addConverterFactory(ScalarsConverterFactory.create())
                .baseUrl("http://3.124.6.203:5000")
                .client(client)
                .build()
            return retrofit.create(ApiServiceInterface::class.java)
        }
    }


    @Headers("Content-type: application/json", "Connection: close", "Accept-Encoding: identity")
    @POST("/")
    fun requestAsync(@Body data: JsonObject): Deferred<Response>
}

    After this changes the issue didn't occure.