Bulk indexing with java high level rest client gives error "Unable to parse response body"

[ivanqwam (Ivan Monnier)]

We are trying to switch from Java Transport Client to Java high level client but we get error "Unable to parse response body" with bulk batches over 10000 documents using high level client.

We had this with many configurations:
6.2 client over 6.2 server
6.5.1 client over 6.2 server
6.5.3 client over 6.5.3 server

For smaller batches, it works, but I cannot tell whether it is the size of the batch or if a bigger batch size means a bigger chance to get a bad document.

Here is the Error printed by our code:

2018/12/20 13:07:01 286-qes5.1.0-DEBUG-QESHost_elastic:bulkAdd() : bulk avant|
2018/12/20 13:07:05 964-qes5.1.0-ERROR:QESHost_elastic:bulkAdd(): Flush impossible:Unable to parse response body|

Here is our code:

public int bulkAdd() throws IOException {

    int iret = 1;
    BulkResponse bulkResponse = null;

    try {
        ses.log(null, "DEBUG", "QESHost_elastic:bulkAdd()", 3, "bulk avant");

        bulkResponse = client.bulk(bulkRequest, RequestOptions.DEFAULT);
        ses.log(null, "DEBUG", "QESHost_elastic:bulkAdd()", 3, "bulk apres", bulkResponse.hasFailures());

        if (bulkResponse.hasFailures()) {

            ses.log(null, "ERROR", "QESHost_elastic:bulkAdd()", 0, "Erreur", bulkResponse.buildFailureMessage());
            // process failures by iterating through each bulk response item
            int ii = 0;
            for (BulkItemResponse bulkItemResponse : bulkResponse) {

                if (bulkItemResponse.isFailed()) {
                    BulkItemResponse.Failure failure = bulkItemResponse.getFailure();
                    ses.log(null, "ERROR", "QESHost_elastic:bulkAdd()", 0, "Item index", bulkItemResponse.getIndex());
                    ses.log(null, "ERROR", "QESHost_elastic:bulkAdd()", 0, "Item id", bulkItemResponse.getId());
                    ses.log(null, "ERROR", "QESHost_elastic:bulkAdd()", 0, "Item itemId", bulkItemResponse.getItemId());
                    ses.log(null, "ERROR", "QESHost_elastic:bulkAdd()", 0, "Item error", failure.getMessage());
                }

                ii++;
            }
            iret = -1;
        }

    } catch (Exception e) {
        **ses.log(con, "ERROR", "QESHost_elastic:bulkAdd()", 0, "Flush impossible", e.getMessage());**
        e.getStackTrace();
        ses.log(con, "ERROR", "QESHost_elastic:bulkAdd()", 0, "Erreur bulk flush", bulkResponse.hasFailures());
        iret = -1;
    }

    return iret;
}

Is there a way to get more information on the reason of this failure ?

Since Java Transport client will soon be deprecated we would be far more comfortable with a working bulk indexing on Java High level client.

[dadoonet (David Pilato)]

Hey Ivan

I don't have the response may be you are sending super big documents and you are hitting the default HTTP size limit? But I'd not expect such a message in that case.
Or may be there is a malformed document or id which is causing the response not to be parsed correctly?

May be you can get more information by adding the httpclient to debug mode?

Anyway and not really related, may I suggest that you look at the BulkProcessor class instead?

[ivanqwam (Ivan Monnier)]

David, you were right at first point : This is the HTTP size limit.

I followed your clue "May be you can get more information by adding the httpclient to debug mode?" which is not as simple as it looks with log4j

I created a log4j2.xml file with this inside

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<Configuration status="DEBUG">
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
    </Console>
  </Appenders>
  <Loggers>
    <Logger name="com.elasticsearch.client" level="DEBUG"/>
    <Logger name="org.apache.http" level="DEBUG"/>
    <Root level="error">
      <AppenderRef ref="Console"/>
    </Root>
  </Loggers>
</Configuration>

I added -Dlog4j.configurationFile=file://$SOFTWARE/conf/log4j2.xml in my command line

This gave me this in the logs

15:54:34.769 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl - http-outgoing-0 127.0.0.1:35116<->127.0.0.1:9200[ACTIVE][rw:rw]: 359 bytes read
15:54:34.770 [I/O dispatcher 1] DEBUG org.apache.http.wire - http-outgoing-0 << "HTTP/1.1 413 Request Entity Too Large[\r][\n]"
15:54:34.770 [I/O dispatcher 1] DEBUG org.apache.http.wire - http-outgoing-0 << "content-length: 0[\r][\n]"
15:54:34.770 [I/O dispatcher 1] DEBUG org.apache.http.wire - http-outgoing-0 << "[\r][\n]"
15:54:34.770 [I/O dispatcher 1] DEBUG org.apache.http.wire - http-outgoing-0 << "HTTP/1.0 400 Bad Request[\r][\n]"
15:54:34.770 [I/O dispatcher 1] DEBUG org.apache.http.wire - http-outgoing-0 << "content-type: application/json; charset=UTF-8[\r][\n]"
15:54:34.770 [I/O dispatcher 1] DEBUG org.apache.http.wire - http-outgoing-0 << "content-length: 203[\r][\n]"
15:54:34.770 [I/O dispatcher 1] DEBUG org.apache.http.wire - http-outgoing-0 << "[\r][\n]"
15:54:34.770 [I/O dispatcher 1] DEBUG org.apache.http.wire - http-outgoing-0 << "{"error":{"root_cause":[{"type":"illegal_argument_exception","reason":"text is empty (possibly HTTP/0.9)"}],"type":"illegal_argument_exception","reason":"text is empty (possibly HTTP/0.9)"},"status":400}"
15:54:34.775 [I/O dispatcher 1] DEBUG org.apache.http.headers - http-outgoing-0 << HTTP/1.1 413 Request Entity Too Large
15:54:34.775 [I/O dispatcher 1] DEBUG org.apache.http.headers - http-outgoing-0 << content-length: 0
15:54:34.775 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.InternalIODispatch - http-outgoing-0 [ACTIVE(299)] Response received
15:54:34.775 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl - http-outgoing-0 127.0.0.1:35116<->127.0.0.1:9200[ACTIVE][r:rw]: Event cleared [w]
15:54:34.775 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.MainClientExec - [exchange: 1] Response received HTTP/1.1 413 Request Entity Too Large
15:54:34.777 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.InternalIODispatch - http-outgoing-0 [ACTIVE(299)] Input ready
15:54:34.778 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.MainClientExec - [exchange: 1] Consume content
15:54:34.778 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl - http-outgoing-0 127.0.0.1:35116<->127.0.0.1:9200[ACTIVE][r:rw]: Close
15:54:34.778 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.InternalHttpAsyncClient - [exchange: 1] Connection cannot be kept alive
15:54:34.778 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.InternalHttpAsyncClient - [exchange: 1] releasing connection

A googling led me to this

https://github.com/elastic/elasticsearch/issues/2902

which made me add this to my conf/elastic.yml file and restart my node

http.max_content_length: 500mb

For good mesure, big documents means a bigger timeout

https://www.elastic.co/guide/en/elasticsearch/client/java-rest/current/_timeouts.html

And I have a working java high level REST client !

No need to bring a Xmas gift for me on your next meetup in Paris, I am so happy with this one.

Please close the case.

Thanks David.