413 Request Entity Too Large error is masked by connection error

[falmanna]

Please include the following information in your ticket.

• CloudantClient (java-cloudant) version(s) that are affected by this issue.
  my dependencies:

<dependency>
	<groupId>com.cloudant</groupId>
	<artifactId>cloudant-client</artifactId>
	<version>2.6.2</version>
</dependency>
<dependency>
	<groupId>com.squareup.okhttp3</groupId>
	<artifactId>okhttp-urlconnection</artifactId>
	<version>3.4.2</version>
</dependency>
<dependency>
          <groupId>commons-io</groupId>
          <artifactId>commons-io</artifactId>
          <version>2.5</version>
</dependency>

• Java version (including vendor and platform).
  Windows 10
  Java 8
  JavaSE 1.8 - jdk 1.8.0_112

• If you're using the optional okhttp dependency.
  yes I am using

• A small code sample that demonstrates the issue.

Database db = cloudant.database(dbName, true);
List<Response> responses = db.bulk(topics); //Error happening here

here is the ERROR LOG

com.cloudant.client.org.lightcouch.CouchDbException: Error retrieving server response
	at com.cloudant.client.org.lightcouch.CouchDbClient.execute(CouchDbClient.java:558) ~[cloudant-client-2.6.2.jar:na]
	at com.cloudant.client.org.lightcouch.CouchDatabaseBase.bulk(CouchDatabaseBase.java:284) ~[cloudant-client-2.6.2.jar:na]
	at com.cloudant.client.api.Database.bulk(Database.java:935) ~[cloudant-client-2.6.2.jar:na]
	at storage.CloudantStorage.insertTopicList(CloudantStorage.java:40) ~[classes/:na]
	at main.MainTaskStream.run(MainTaskStream.java:122) ~[classes/:na]
	at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) [na:1.8.0_112]
	at java.util.concurrent.FutureTask.runAndReset(Unknown Source) [na:1.8.0_112]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(Unknown Source) [na:1.8.0_112]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) [na:1.8.0_112]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [na:1.8.0_112]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [na:1.8.0_112]
	at java.lang.Thread.run(Unknown Source) [na:1.8.0_112]
Caused by: java.io.IOException: Error writing request body to server
	at sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.checkError(Unknown Source) ~[na:1.8.0_112]
	at sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.write(Unknown Source) ~[na:1.8.0_112]
	**at org.apache.commons.io.IOUtils.copyLarge(IOUtils.java:2147) ~[commons-io-2.5.jar:2.5]
	at com.cloudant.http.HttpConnection.execute(HttpConnection.java:336) ~[cloudant-http-2.6.2.jar:na]
	at com.cloudant.client.org.lightcouch.CouchDbClient.execute(CouchDbClient.java:481) ~[cloudant-client-2.6.2.jar:na]**
	... 11 common frames omitted

I traced the code to find the error, it leads me to this code from inside the library

public static long copyLarge(final InputStream input, final OutputStream output, final byte[] buffer)
            throws IOException {
        long count = 0;
        int n;
        while (EOF != (n = input.read(buffer))) {
            output.write(buffer, 0, n); //ERROR happened here, looks like it is happening because of closed OutputStream as noted from write() method description, but I couldn't find why?  
            count += n;
        }
        return count;
    }

NOTES:

• I am able to read docs from this database and write single documents, but failing to bulk insert.
• The inserted List size is less than 300KB.
• The code is running with a local instant of CouchDB without any errors.

thank you.

[ricellis]

@firasalmanna thanks for reporting this. I notice you have an okhttp dependency of version 3.4.2, but java-cloudant version 2.6.2 is only compatible with version 2.7.5. The updated dependency to 3.4.2 has merged to master, but we haven't done a java-cloudant release with that version yet. So unfortunately the master branch README is out of step with the release. We recommended using the README and documentation from the release tags, which you can see on the releases page.

Let us know if changing the okhttp dependency version to 2.7.5 resolves your issue.

[falmanna]

@ricellis Thank you for your response.
I've changed the dependency version, the error has changed a bit, but I think it is still the same error.
Here is the log:

11:56:56.385 [pool-1-thread-1] ERROR main.MainTaskStream - Error retrieving server response
com.cloudant.client.org.lightcouch.CouchDbException: Error retrieving server response
    at com.cloudant.client.org.lightcouch.CouchDbClient.execute(CouchDbClient.java:558) ~[cloudant-client-2.6.2.jar:na]
    at com.cloudant.client.org.lightcouch.CouchDatabaseBase.bulk(CouchDatabaseBase.java:284) ~[cloudant-client-2.6.2.jar:na]
    at com.cloudant.client.api.Database.bulk(Database.java:935) ~[cloudant-client-2.6.2.jar:na]
    at storage.CloudantStorage.insertTopicList(CloudantStorage.java:40) ~[classes/:na]
    at main.MainTaskStream.run(MainTaskStream.java:124) ~[classes/:na]
    at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) [na:1.8.0_112]
    at java.util.concurrent.FutureTask.runAndReset(Unknown Source) [na:1.8.0_112]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(Unknown Source) [na:1.8.0_112]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) [na:1.8.0_112]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [na:1.8.0_112]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [na:1.8.0_112]
    at java.lang.Thread.run(Unknown Source) [na:1.8.0_112]
Caused by: java.net.SocketException: Connection reset by peer: socket write error
    at java.net.SocketOutputStream.socketWrite0(Native Method) ~[na:1.8.0_112]
    at java.net.SocketOutputStream.socketWrite(Unknown Source) ~[na:1.8.0_112]
    at java.net.SocketOutputStream.write(Unknown Source) ~[na:1.8.0_112]
    at sun.security.ssl.OutputRecord.writeBuffer(Unknown Source) ~[na:1.8.0_112]
    at sun.security.ssl.OutputRecord.write(Unknown Source) ~[na:1.8.0_112]
    at sun.security.ssl.SSLSocketImpl.writeRecordInternal(Unknown Source) ~[na:1.8.0_112]
    at sun.security.ssl.SSLSocketImpl.writeRecord(Unknown Source) ~[na:1.8.0_112]
    at sun.security.ssl.AppOutputStream.write(Unknown Source) ~[na:1.8.0_112]
    at okio.Okio$1.write(Okio.java:80) ~[okio-1.6.0.jar:na]
    at okio.AsyncTimeout$1.write(AsyncTimeout.java:155) ~[okio-1.6.0.jar:na]
    at okio.RealBufferedSink.emitCompleteSegments(RealBufferedSink.java:176) ~[okio-1.6.0.jar:na]
    at okio.RealBufferedSink.write(RealBufferedSink.java:46) ~[okio-1.6.0.jar:na]
    at com.squareup.okhttp.internal.http.Http1xStream$FixedLengthSink.write(Http1xStream.java:288) ~[okhttp-2.7.5.jar:na]
    at okio.RealBufferedSink.emitCompleteSegments(RealBufferedSink.java:176) ~[okio-1.6.0.jar:na]
    at okio.RealBufferedSink$1.write(RealBufferedSink.java:198) ~[okio-1.6.0.jar:na]
    at org.apache.commons.io.IOUtils.copyLarge(IOUtils.java:1793) ~[commons-io-2.4.jar:2.4]
    at com.cloudant.http.HttpConnection.execute(HttpConnection.java:336) ~[cloudant-http-2.6.2.jar:na]
    at com.cloudant.client.org.lightcouch.CouchDbClient.execute(CouchDbClient.java:481) ~[cloudant-client-2.6.2.jar:na]
    ... 11 common frames omitted

I think it is related to closed outputStream, but I am not sure why!
Note that I tried to use it without okhttp, but I received the problem.

[ricellis]

Yeah the okhttp version issue causes fallback to the JVM's default HttpURLConnection, but that should still work anyway.

It does seem though that the okhttp dependency propagates a more information:
Caused by: java.net.SocketException: Connection reset by peer: socket write error

So it looks like the server closed the connection, which would tally with a closed output stream. Are you using a proxy or connecting directly? Maybe contact support@cloudant.com and see if they can identify why the server is closing the connection.

[falmanna]

I am connecting directly using username and password.
I tried to insert one item from my list instead of the whole list, it worked without any error. so I think the connection is being closed in larger requests.

Something important to note is that I am using Cloudant service from within bluemix, I created an account on Cloudant website directly, and run my code against this new DB, it worked perfectly!!
I will contact Bluemix to report this, and I will update this issue once I have a response.

Thank you.

[falmanna]

I contacted Bluemix and I got why the connection is being closed.
on Bluemix's Cloudant service, the free plan has a limit on 10 writes/sec, so if your bulk insert has more than 10 items, the connection will be closed.
This is different that Cloudant.com plan, as they count API requests, so a bulk insert will be counted as a single API request.

[mikerhodes]

That's not correct, we don't close the network connection on exceeding the rate limit, instead you receive an error. I'm reopening the issue, I don't think we've got to the bottom of this.

[falmanna]

@mikerhodes You are correct, actually I got this response from Bluemix support team, but didn't test it because my code ran successfully on cloudant.com, so I thought this was the problem.

I did a test now, and here are the results:

1. I tried to bulk insert 20 empty items, each contains just (id, rev, timestamp). All items got inserted successfully. I change the number to 200, and then 2000 and all got inserted successfully.
2. Then I tried to bulk insert 700 items but with data, each item is around 5KB, this time I got the same Connection reset by peer: socket write error error.

My conclusion, there is no limit on the number of items, even tho I am using lite plan, which should limit me to 10 writes/second. But there is a limit on the size/or duration of the request, and that's why the connection is being closed.

[ricellis]

The maximum request size is 1 MB. It appears that the server is returning a 413 Request Entity Too Large, but in line with the HTTP spec it is also closing the connection to prevent the client continuing the request. I think we should use this ticket to investigate whether we can handle the 413 case better in the client, by actually returning the exception with the 413 response code.

[falmanna]

@ricellis I just finished chatting with Bluemix support, you are correct, my bulk insert was more than 1MB, I tested it again with 800KB request, and it worked.
I think the SDK is not handling this case well by returning the right Exception, that's why we got confused.

[ricellis]

At the moment I don't believe there is a way for the HttpURLConnection to read the response code before completing the sending of the request body, which it cannot do if the server closes the connection. After the connection is closed it can't read the response code.
Marking for later milestone to see if we can come up with another way to get a better exception thrown, possibly through re-enabling Expect: 100-Continue (although in my current testing this did not appear to get an immediate 413 response from the server either).