RestHighLevelClient low performance for search

[epoddubny]

Elasticsearch version: 6.6.1

JVM version : openjdk version "1.8.0_191", oracle jdk 1.8.0_131

OS version: Linux 3.10.0-957.1.3.el7.x86_64, OS X 18.6.0 Darwin Kernel Version 18.6.0

Description of the problem including expected versus actual behavior:

I decided to open the issue after this discussion https://discuss.elastic.co/t/resthighlevelclient-slow-performance/182746/2

I noticed that requests executed through RestHighLevelClient for search slower than the same requests executed through curl, Postman or my own implementation for search.

In VisualVM I can see that search request takes 401ms.

But if I copy this request from logs and call it in Postman it takes 65ms.

Then I wrote my own implementation for search and compared it with the standard implementation.

private fun searchRequest(index: Index,
                          indexType: IndexType,
                          source: SearchSourceBuilder): SearchResponse {
    val searchRequest = SearchRequest(index.index)
            .types(indexType.type)
            .source(source)

    val request = Converter.createSearchRequest(searchRequest).entity.content
    val writer = StringWriter()
    IOUtils.copy(request, write, StandardCharsets.UTF_8.name())
    val httpEntity = HttpEntity(writer.toString(), getHeders())

    val postForEntity = restTemplateElastic.postForEntity(getHost(), httpEntity, String::class.java)

    val httpEntityResponse = BasicHttpEntity()
    httpEntityResponse.content = IOUtils.toInputStream(postForEntity.body, StandardCharsets.UTF_8.name())
    return Converter.createSearchResponse(httpEntityResponse, restHighLevelClient)
}

public class Converter {
    public static Request createSearchRequest(SearchRequest searchRequest) {
        try {
            return RequestConverters.search(searchRequest, "_search");
        } catch (Exception e) {
            throw new IllegalStateException(e);
        }
    }

    public static SearchResponse createSearchResponse(BasicHttpEntity httpEntity, RestHighLevelClient restHighLevelClient) {
        try {
            if (httpEntity.getContentType() == null) {
                httpEntity.setContentType("application/json");
            }
            return restHighLevelClient.parseEntity(httpEntity, SearchResponse::fromXContent);
        } catch (Exception e) {
            throw new IllegalStateException(e);
        }
    }
}

it's faster approximately 13 times

My implementation:

Lifting the server siege...
Transactions: 25226 hits
Availability: 100.00 %
Elapsed time: 61.06 secs
Data transferred: 314.29 MB
Response time: 0.24 secs
Transaction rate: 413.13 trans/sec
Throughput: 5.15 MB/sec
Concurrency: 99.83
Successful transactions: 25226
Failed transactions: 0
Longest transaction: 8.00
Shortest transaction: 0.06

RestHighLevelClient.search

Lifting the server siege...
Transactions: 1886 hits
Availability: 100.00 %
Elapsed time: 60.78 secs
Data transferred: 23.49 MB
Response time: 3.15 secs
Transaction rate: 31.03 trans/sec
Throughput: 0.39 MB/sec
Concurrency: 97.60
Successful transactions: 1886
Failed transactions: 0
Longest transaction: 6.77
Shortest transaction: 0.80

Steps to reproduce:
Add maven dependency:

<dependency>
    <groupId>org.elasticsearch.client</groupId>
    <artifactId>elasticsearch-rest-high-level-client</artifactId>
    <version>6.8.0</version>
</dependency>

Create RestHighLevelClient:

    @Bean
    fun restHighLevelClient(): RestHighLevelClient {
        val trustStrategy = TrustSelfSignedStrategy()
        
        val credentialsProvider = BasicCredentialsProvider()
                .apply { setCredentials(AuthScope.ANY, UsernamePasswordCredentials(username, password)) }

        return RestHighLevelClient(RestClient.builder(
                *getHosts(hosts)
        ).setHttpClientConfigCallback {
            it
                    .setMaxConnPerRoute(75)
                    .setMaxConnTotal(150)
                    .setDefaultCredentialsProvider(credentialsProvider)
        }
        )
    }

And define the search function:

private fun searchRequest(index: Index,
                              indexType: IndexType,
                              source: SearchSourceBuilder): SearchResponse {
        val searchRequest = SearchRequest(index.index)
                .types(indexType.type)
                .source(source)

        return restHighLevelClient.search(searchRequest, RequestOptions.DEFAULT)
}

Provide logs:

Show logs

2019-05-26 10:14:52.572 DEBUG 925 --- [nio-8080-exec-3] o.a.http.impl.nio.client.MainClientExec : [exchange: 3] start execution
2019-05-26 10:14:52.572 DEBUG 925 --- [nio-8080-exec-3] o.a.h.client.protocol.RequestAddCookies : CookieSpec selected: default
2019-05-26 10:14:52.573 DEBUG 925 --- [nio-8080-exec-3] o.a.h.client.protocol.RequestAuthCache : Re-using cached 'basic' auth scheme for https://myserver.com:9200
2019-05-26 10:14:52.573 DEBUG 925 --- [nio-8080-exec-3] o.a.h.i.n.c.InternalHttpAsyncClient : [exchange: 3] Request connection for {s}->https://myserver.com:9200
2019-05-26 10:14:52.573 DEBUG 925 --- [nio-8080-exec-3] .n.c.PoolingNHttpClientConnectionManager : Connection request: [route: {s}->https://myserver.com:9200][total kept alive: 1; route allocated: 0 of 75; total allocated: 1 of 150]
2019-05-26 10:14:52.679 DEBUG 925 --- [O dispatcher 10] .n.c.PoolingNHttpClientConnectionManager : Connection leased: [id: http-outgoing-1][route: {s}->https://myserver.com:9200][total kept alive: 1; route allocated: 1 of 75; total allocated: 1 of 150]
2019-05-26 10:14:52.680 DEBUG 925 --- [O dispatcher 10] o.a.h.i.n.c.InternalHttpAsyncClient : [exchange: 3] Connection allocated: CPoolProxy{http-outgoing-1 [ACTIVE]}
2019-05-26 10:14:52.680 DEBUG 925 --- [O dispatcher 10] h.i.n.c.ManagedNHttpClientConnectionImpl : http-outgoing-1 10.80.96.37:50740<->10.9.69.40:9200[ACTIVE][r:]: Set attribute http.nio.exchange-handler
2019-05-26 10:14:52.680 DEBUG 925 --- [O dispatcher 10] h.i.n.c.ManagedNHttpClientConnectionImpl : http-outgoing-1 10.80.96.37:50740<->10.9.69.40:9200[ACTIVE][rw:]: Event set [w]
2019-05-26 10:14:52.680 DEBUG 925 --- [O dispatcher 10] h.i.n.c.ManagedNHttpClientConnectionImpl : http-outgoing-1 10.80.96.37:50740<->10.9.69.40:9200[ACTIVE][rw:]: Set timeout 0
2019-05-26 10:14:52.680 DEBUG 925 --- [O dispatcher 10] o.a.h.i.nio.client.InternalIODispatch : http-outgoing-1 [ACTIVE]: Connected
2019-05-26 10:14:52.680 DEBUG 925 --- [O dispatcher 10] h.i.n.c.ManagedNHttpClientConnectionImpl : http-outgoing-1 10.80.96.37:50740<->10.9.69.40:9200[ACTIVE][rw:]: Set attribute http.nio.http-exchange-state
2019-05-26 10:14:52.680 DEBUG 925 --- [O dispatcher 10] o.a.h.i.n.c.InternalHttpAsyncClient : [exchange: 3] Start connection routing
2019-05-26 10:14:52.682 DEBUG 925 --- [O dispatcher 10] h.i.n.c.ManagedNHttpClientConnectionImpl : http-outgoing-1 Upgrade session 10.80.96.37:50740<->10.9.69.40:9200[ACTIVE][rw:][ACTIVE][rw][NEED_UNWRAP][0][0][249]
2019-05-26 10:14:52.682 DEBUG 925 --- [O dispatcher 10] o.a.h.i.n.c.InternalHttpAsyncClient : [exchange: 3] route completed
2019-05-26 10:14:52.682 DEBUG 925 --- [O dispatcher 10] o.a.http.impl.nio.client.MainClientExec : [exchange: 3] Connection route established
2019-05-26 10:14:52.682 DEBUG 925 --- [O dispatcher 10] o.a.http.impl.nio.client.MainClientExec : [exchange: 3] Attempt 1 to execute request
2019-05-26 10:14:52.682 DEBUG 925 --- [O dispatcher 10] o.a.http.impl.nio.client.MainClientExec : [exchange: 3] Target auth state: UNCHALLENGED
2019-05-26 10:14:52.682 DEBUG 925 --- [O dispatcher 10] o.a.http.impl.nio.client.MainClientExec : [exchange: 3] Proxy auth state: UNCHALLENGED
2019-05-26 10:14:52.682 DEBUG 925 --- [O dispatcher 10] h.i.n.c.ManagedNHttpClientConnectionImpl : http-outgoing-1 10.80.96.37:50740<->10.9.69.40:9200[ACTIVE][rw:][ACTIVE][rw][NEED_UNWRAP][0][0][249]: Set timeout 30000
2019-05-26 10:14:52.683 DEBUG 925 --- [O dispatcher 10] org.apache.http.headers : http-outgoing-1 >> POST /search-index/fulfillment_task/_search?typed_keys=true&ignore_unavailable=false&expand_wildcards=open&allow_no_indices=true&search_type=query_then_fetch&batched_reduce_size=512 HTTP/1.1
2019-05-26 10:14:52.683 DEBUG 925 --- [O dispatcher 10] org.apache.http.headers : http-outgoing-1 >> Content-Length: 156
2019-05-26 10:14:52.683 DEBUG 925 --- [O dispatcher 10] org.apache.http.headers : http-outgoing-1 >> Content-Type: application/json
2019-05-26 10:14:52.683 DEBUG 925 --- [O dispatcher 10] org.apache.http.headers : http-outgoing-1 >> Host: myserver.com:9200
2019-05-26 10:14:52.683 DEBUG 925 --- [O dispatcher 10] org.apache.http.headers : http-outgoing-1 >> Connection: Keep-Alive
2019-05-26 10:14:52.683 DEBUG 925 --- [O dispatcher 10] org.apache.http.headers : http-outgoing-1 >> User-Agent: Apache-HttpAsyncClient/4.1.4 (Java/1.8.0_131)
2019-05-26 10:14:52.683 DEBUG 925 --- [O dispatcher 10] org.apache.http.headers : http-outgoing-1 >> Authorization: Basic ******
2019-05-26 10:14:52.683 DEBUG 925 --- [O dispatcher 10] h.i.n.c.ManagedNHttpClientConnectionImpl : http-outgoing-1 10.80.96.37:50740<->10.9.69.40:9200[ACTIVE][rw:][ACTIVE][rw][NEED_UNWRAP][0][0][249]: Event set [w]
2019-05-26 10:14:53.044 DEBUG 925 --- [O dispatcher 10] o.a.h.i.nio.client.InternalIODispatch : http-outgoing-1 [ACTIVE] Output ready
2019-05-26 10:14:53.044 DEBUG 925 --- [O dispatcher 10] o.a.http.impl.nio.client.MainClientExec : [exchange: 3] produce content
2019-05-26 10:14:53.044 DEBUG 925 --- [O dispatcher 10] o.a.http.impl.nio.client.MainClientExec : [exchange: 3] Request completed
2019-05-26 10:14:53.044 DEBUG 925 --- [O dispatcher 10] o.a.h.i.nio.client.InternalIODispatch : http-outgoing-1 [ACTIVE] [content length: 156; pos: 156; completed: true]
2019-05-26 10:14:53.045 DEBUG 925 --- [O dispatcher 10] h.i.n.c.ManagedNHttpClientConnectionImpl : http-outgoing-1 10.80.96.37:50740<->10.9.69.40:9200[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][661]: 580 bytes written
2019-05-26 10:14:53.045 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 >> "POST /search-index/fulfillment_task/_search?typed_keys=true&ignore_unavailable=false&expand_wildcards=open&allow_no_indices=true&search_type=query_then_fetch&batched_reduce_size=512 HTTP/1.1[\r][\n]"
2019-05-26 10:14:53.045 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 >> "Content-Length: 156[\r][\n]"
2019-05-26 10:14:53.045 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 >> "Content-Type: application/json[\r][\n]"
2019-05-26 10:14:53.045 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 >> "Host: myserver.com:9200[\r][\n]"
2019-05-26 10:14:53.045 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 >> "Connection: Keep-Alive[\r][\n]"
2019-05-26 10:14:53.045 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 >> "User-Agent: Apache-HttpAsyncClient/4.1.4 (Java/1.8.0_131)[\r][\n]"
2019-05-26 10:14:53.045 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 >> "Authorization: Basic *****[\r][\n]"
2019-05-26 10:14:53.045 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 >> "[\r][\n]"
2019-05-26 10:14:53.045 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 >> "{"from":30,"size":30,"query":{"bool":{"adjust_pure_negative":true,"boost":1.0}},"_source":{"includes":[],"excludes":[""]},"sort":[{"_id":{"order":"asc"}}]}"
2019-05-26 10:14:53.045 DEBUG 925 --- [O dispatcher 10] o.a.h.i.nio.client.InternalIODispatch : http-outgoing-1 [ACTIVE] Request ready
2019-05-26 10:14:53.045 DEBUG 925 --- [O dispatcher 10] h.i.n.c.ManagedNHttpClientConnectionImpl : http-outgoing-1 10.80.96.37:50740<->10.9.69.40:9200[ACTIVE][r:w][ACTIVE][r][NOT_HANDSHAKING][0][0][0]: Event cleared [w]
2019-05-26 10:14:53.109 DEBUG 925 --- [O dispatcher 10] h.i.n.c.ManagedNHttpClientConnectionImpl : http-outgoing-1 10.80.96.37:50740<->10.9.69.40:9200[ACTIVE][r:r][ACTIVE][r][NOT_HANDSHAKING][0][0][0]: 4214 bytes read
2019-05-26 10:14:53.109 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 << "HTTP/1.1 200 OK[\r][\n]"
2019-05-26 10:14:53.109 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 << "content-type: application/json; charset=UTF-8[\r][\n]"
2019-05-26 10:14:53.109 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 << "content-length: 4126[\r][\n]"
2019-05-26 10:14:53.109 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 << "[\r][\n]"
2019-05-26 10:14:53.110 DEBUG 925 --- [O dispatcher 10] org.apache.http.wire : http-outgoing-1 << "{"took":7,"timed_out":false,"_shards":{"total":5,"successful":5,"skipped":0,"failed":0},"hits":{"total":2980,"max_score":null,"hits":[{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000317","_score":null,"_source":{},"sort":["2004919050000317"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000318","_score":null,"_source":{},"sort":["2004919050000318"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000320","_score":null,"_source":{},"sort":["2004919050000320"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000347","_score":null,"_source":{},"sort":["2004919050000347"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000350","_score":null,"_source":{},"sort":["2004919050000350"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000356","_score":null,"_source":{},"sort":["2004919050000356"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000363","_score":null,"_source":{},"sort":["2004919050000363"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000364","_score":null,"_source":{},"sort":["2004919050000364"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000365","_score":null,"_source":{},"sort":["2004919050000365"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000366","_score":null,"_source":{},"sort":["2004919050000366"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000367","_score":null,"_source":{},"sort":["2004919050000367"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000369","_score":null,"_source":{},"sort":["2004919050000369"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000370","_score":null,"_source":{},"sort":["2004919050000370"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000371","_score":null,"_source":{},"sort":["2004919050000371"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000372","_score":null,"_source":{},"sort":["2004919050000372"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000373","_score":null,"_source":{},"sort":["2004919050000373"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000375","_score":null,"_source":{},"sort":["2004919050000375"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000401","_score":null,"_source":{},"sort":["2004919050000401"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000402","_score":null,"_source":{},"sort":["2004919050000402"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000403","_score":null,"_source":{},"sort":["2004919050000403"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000404","_score":null,"_source":{},"sort":["2004919050000404"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000405","_score":null,"_source":{},"sort":["2004919050000405"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000406","_score":null,"_source":{},"sort":["2004919050000406"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000407","_score":null,"_source":{},"sort":["2004919050000407"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000408","_score":null,"_source":{},"sort":["2004919050000408"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000409","_score":null,"_source":{},"sort":["2004919050000409"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000410","_score":null,"_source":{},"sort":["2004919050000410"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000411","_score":null,"_source":{},"sort":["2004919050000411"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000412","_score":null,"_source":{},"sort":["2004919050000412"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000413","_score":null,"_source":{},"sort":["2004919050000413"]}]}}"
2019-05-26 10:14:53.110 DEBUG 925 --- [O dispatcher 10] org.apache.http.headers : http-outgoing-1 << HTTP/1.1 200 OK
2019-05-26 10:14:53.111 DEBUG 925 --- [O dispatcher 10] org.apache.http.headers : http-outgoing-1 << content-type: application/json; charset=UTF-8
2019-05-26 10:14:53.111 DEBUG 925 --- [O dispatcher 10] org.apache.http.headers : http-outgoing-1 << content-length: 4126
2019-05-26 10:14:53.111 DEBUG 925 --- [O dispatcher 10] o.a.h.i.nio.client.InternalIODispatch : http-outgoing-1 [ACTIVE(4126)] Response received
2019-05-26 10:14:53.111 DEBUG 925 --- [O dispatcher 10] o.a.http.impl.nio.client.MainClientExec : [exchange: 3] Response received HTTP/1.1 200 OK
2019-05-26 10:14:53.111 DEBUG 925 --- [O dispatcher 10] o.a.h.i.nio.client.InternalIODispatch : http-outgoing-1 [ACTIVE(4126)] Input ready
2019-05-26 10:14:53.111 DEBUG 925 --- [O dispatcher 10] o.a.http.impl.nio.client.MainClientExec : [exchange: 3] Consume content
2019-05-26 10:14:53.111 DEBUG 925 --- [O dispatcher 10] o.a.h.i.n.c.InternalHttpAsyncClient : [exchange: 3] Connection can be kept alive indefinitely
2019-05-26 10:14:53.111 DEBUG 925 --- [O dispatcher 10] o.a.http.impl.nio.client.MainClientExec : [exchange: 3] Response processed
2019-05-26 10:14:53.111 DEBUG 925 --- [O dispatcher 10] o.a.h.i.n.c.InternalHttpAsyncClient : [exchange: 3] releasing connection
2019-05-26 10:14:53.111 DEBUG 925 --- [O dispatcher 10] h.i.n.c.ManagedNHttpClientConnectionImpl : http-outgoing-1 10.80.96.37:50740<->10.9.69.40:9200[ACTIVE][r:r][ACTIVE][r][NOT_HANDSHAKING][0][0][0]: Remove attribute http.nio.exchange-handler
2019-05-26 10:14:53.112 DEBUG 925 --- [O dispatcher 10] .n.c.PoolingNHttpClientConnectionManager : Releasing connection: [id: http-outgoing-1][route: {s}->https://myserver.com:9200][total kept alive: 1; route allocated: 1 of 75; total allocated: 2 of 150]
2019-05-26 10:14:53.112 DEBUG 925 --- [O dispatcher 10] .n.c.PoolingNHttpClientConnectionManager : Connection [id: http-outgoing-1][route: {s}->https://myserver.com:9200][state: CN=client] can be kept alive indefinitely
2019-05-26 10:14:53.112 DEBUG 925 --- [O dispatcher 10] h.i.n.c.ManagedNHttpClientConnectionImpl : http-outgoing-1 10.80.96.37:50740<->10.9.69.40:9200[ACTIVE][r:r][ACTIVE][r][NOT_HANDSHAKING][0][0][0]: Set timeout 0
2019-05-26 10:14:53.112 DEBUG 925 --- [O dispatcher 10] .n.c.PoolingNHttpClientConnectionManager : Connection released: [id: http-outgoing-1][route: {s}->https://myserver.com:9200][state: CN=client][total kept alive: 2; route allocated: 1 of 75; total allocated: 2 of 150]
2019-05-26 10:14:53.112 DEBUG 925 --- [O dispatcher 10] org.elasticsearch.client.RestClient : request [POST https://myserver.com:9200/search-index/fulfillment_task/_search?typed_keys=true&ignore_unavailable=false&expand_wildcards=open&allow_no_indices=true&search_type=query_then_fetch&batched_reduce_size=512] returned [HTTP/1.1 200 OK]
2019-05-26 10:14:53.112 TRACE 925 --- [O dispatcher 10] tracer : curl -iX POST 'https://myserver.com:9200/search-index/fulfillment_task/_search?typed_keys=true&ignore_unavailable=false&expand_wildcards=open&allow_no_indices=true&search_type=query_then_fetch&batched_reduce_size=512' -d '{"from":30,"size":30,"query":{"bool":{"adjust_pure_negative":true,"boost":1.0}},"_source":{"includes":[],"excludes":[""]},"sort":[{"_id":{"order":"asc"}}]}'
HTTP/1.1 200 OK
content-type: application/json; charset=UTF-8
content-length: 4126

{"took":7,"timed_out":false,"_shards":{"total":5,"successful":5,"skipped":0,"failed":0},"hits":{"total":2980,"max_score":null,"hits":[{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000317","_score":null,"_source":{},"sort":["2004919050000317"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000318","_score":null,"_source":{},"sort":["2004919050000318"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000320","_score":null,"_source":{},"sort":["2004919050000320"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000347","_score":null,"_source":{},"sort":["2004919050000347"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000350","_score":null,"_source":{},"sort":["2004919050000350"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000356","_score":null,"_source":{},"sort":["2004919050000356"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000363","_score":null,"_source":{},"sort":["2004919050000363"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000364","_score":null,"_source":{},"sort":["2004919050000364"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000365","_score":null,"_source":{},"sort":["2004919050000365"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000366","_score":null,"_source":{},"sort":["2004919050000366"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000367","_score":null,"_source":{},"sort":["2004919050000367"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000369","_score":null,"_source":{},"sort":["2004919050000369"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000370","_score":null,"_source":{},"sort":["2004919050000370"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000371","_score":null,"_source":{},"sort":["2004919050000371"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000372","_score":null,"_source":{},"sort":["2004919050000372"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000373","_score":null,"_source":{},"sort":["2004919050000373"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000375","_score":null,"_source":{},"sort":["2004919050000375"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000401","_score":null,"_source":{},"sort":["2004919050000401"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000402","_score":null,"_source":{},"sort":["2004919050000402"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000403","_score":null,"_source":{},"sort":["2004919050000403"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000404","_score":null,"_source":{},"sort":["2004919050000404"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000405","_score":null,"_source":{},"sort":["2004919050000405"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000406","_score":null,"_source":{},"sort":["2004919050000406"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000407","_score":null,"_source":{},"sort":["2004919050000407"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000408","_score":null,"_source":{},"sort":["2004919050000408"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000409","_score":null,"_source":{},"sort":["2004919050000409"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000410","_score":null,"_source":{},"sort":["2004919050000410"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000411","_score":null,"_source":{},"sort":["2004919050000411"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000412","_score":null,"_source":{},"sort":["2004919050000412"]},{"_index":"search-index","_type":"fulfillment_task","_id":"2004919050000413","_score":null,"_source":{},"sort":["2004919050000413"]}]}}
2019-05-26 10:14:53.112 DEBUG 925 --- [O dispatcher 10] o.a.h.i.nio.client.InternalIODispatch : http-outgoing-1 [ACTIVE] [content length: 4126; pos: 4126; completed: true]

[elasticmachine]

Pinging @elastic/es-core-features

[hub-cap]

Hi, can you check out #39890 to see if you are having the same issue. Try to disable string interning and see if it speeds things up

[javanna]

I noticed that requests executed through RestHighLevelClient for search slower than the same requests executed through curl, Postman or my own implementation for search.

It is expected that curl or postman are faster, as they don't parse back the json format. How long the parsing takes obviously depends on what the response looks like. As for your own implementation, it seems that you reused our parsing code, yet you switched to a different http client. What client is that?

@hub-cap If I understand correctly, here we are comparing performance of the two client implementations, while the parsing code (which I think is responsible for the strings interning) stays the same.

[epoddubny]

I noticed that requests executed through RestHighLevelClient for search slower than the same requests executed through curl, Postman or my own implementation for search.

It is expected that curl or postman are faster, as they don't parse back the json format. How long the parsing takes obviously depends on what the response looks like. As for your own implementation, it seems that you reused our parsing code, yet you switched to a different http client. What client is that?

@hub-cap If I understand correctly, here we are comparing performance of the two client implementations, while the parsing code (which I think is responsible for the strings interning) stays the same.

Yes, I reused your parsing code, but with different http clients. I used DefaultWebClient from Spring 5 and Apache http client. They both were faster.

[hub-cap]

@javanna since ES is parsing it, I was hoping the string interning issue that a few people have commented on would have sped it up. Definitely not as fast as something that does not parse, but make it faster for the user.

Im also trying to get somewhat circumstantial evidence on whether turning off interning here helps, because its been discussed a few times and we are on the fence of whether we should turn it off or not.

[hub-cap]

ok sorry, i think i misunderstood some things here. Im going to work to repro this issue. It will take a few days as i have some other things on my plate.

[dakrone]

Closing this as we've removed the high level rest client in favor of the Java client.