Home > Enterprise >  elasticsearch java response stuck
elasticsearch java response stuck

Time：08-05

I use spring data elasticsearch to query and save doc into elasticsearch(7.12):

  • spring boot: 2.7.1
  • spring-boot-starter-data-elasticsearch: 2.7.1
  • spring-data-elasticsearch: 4.4.1

after running a while, all the worker threads stuck when invoking CrudRepository#save method to save doc. Here is one thread dump:

status: org.apache.http.concurrent.BasicFuture@11ab10df WAITING


java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:502)
org.apache.http.concurrent.BasicFuture.get(BasicFuture.java:82)
org.apache.http.impl.nio.client.FutureWrapper.get(FutureWrapper.java:70)
org.elasticsearch.client.RestClient.performRequest(RestClient.java:295)
org.elasticsearch.client.RestClient.performRequest(RestClient.java:287)
org.elasticsearch.client.RestHighLevelClient.performClientRequest(RestHighLevelClient.java:2699)
org.elasticsearch.client.RestHighLevelClient.internalPerformRequest(RestHighLevelClient.java:2171)
org.elasticsearch.client.RestHighLevelClient.performRequest(RestHighLevelClient.java:2137)
org.elasticsearch.client.RestHighLevelClient.performRequestAndParseEntity(RestHighLevelClient.java:2105)
org.elasticsearch.client.IndicesClient.refresh(IndicesClient.java:900)
org.springframework.data.elasticsearch.core.RestIndexTemplate.lambda$doRefresh$8(RestIndexTemplate.java:178)
org.springframework.data.elasticsearch.core.RestIndexTemplate$$Lambda$1112/1741758039.doWithClient(Unknown Source)
org.springframework.data.elasticsearch.core.ElasticsearchRestTemplate.execute(ElasticsearchRestTemplate.java:582)
org.springframework.data.elasticsearch.core.RestIndexTemplate.doRefresh(RestIndexTemplate.java:178)
org.springframework.data.elasticsearch.core.AbstractIndexTemplate.refresh(AbstractIndexTemplate.java:163)
org.springframework.data.elasticsearch.repository.support.SimpleElasticsearchRepository.doRefresh(SimpleElasticsearchRepository.java:313)
org.springframework.data.elasticsearch.repository.support.SimpleElasticsearchRepository.executeAndRefresh(SimpleElasticsearchRepository.java:361)
org.springframework.data.elasticsearch.repository.support.SimpleElasticsearchRepository.save(SimpleElasticsearchRepository.java:188)
sun.reflect.GeneratedMethodAccessor62.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:498)
org.springframework.data.repository.core.support.RepositoryMethodInvoker$RepositoryFragmentMethodInvoker.lambda$new$0(RepositoryMethodInvoker.java:289)
org.springframework.data.repository.core.support.RepositoryMethodInvoker$RepositoryFragmentMethodInvoker$$Lambda$1061/168251875.invoke(Unknown Source)
org.springframework.data.repository.core.support.RepositoryMethodInvoker.doInvoke(RepositoryMethodInvoker.java:137)
org.springframework.data.repository.core.support.RepositoryMethodInvoker.invoke(RepositoryMethodInvoker.java:121)
org.springframework.data.repository.core.support.RepositoryComposition$RepositoryFragments.invoke(RepositoryComposition.java:530)
org.springframework.data.repository.core.support.RepositoryComposition.invoke(RepositoryComposition.java:286)
org.springframework.data.repository.core.support.RepositoryFactorySupport$ImplementationMethodExecutionInterceptor.invoke(RepositoryFactorySupport.java:640)
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.doInvoke(QueryExecutorMethodInterceptor.java:164)
org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.invoke(QueryExecutorMethodInterceptor.java:139)
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
com.sun.proxy.$Proxy64.save(Unknown Source)
sun.reflect.GeneratedMethodAccessor60.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:498)
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:137)
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
com.sun.proxy.$Proxy64.save(Unknown Source)
...

Seems that it stuck on this code line(RestClient.java:295) to wait for es response but never got it, so Future#get() is wait forever:

        try {
            httpResponse = client.execute(context.requestProducer, context.asyncResponseConsumer, context.context, null).get();
        } catch (Exception e) {

What i wanna know is why it doesn't throw something like TimeoutException rather than wait the response forever?

Plus, timeout is set to 30s and keep alive is enabled by default, and all these info can be found in the below debug log:

2022-08-02 17:43:28.652 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl 154 - http-outgoing-0 10.234.8.18:39418<->103.74.51.222:443[ACTIVE][rw:][ACTIVE][rw][NEED_UNWRAP][0][0][311]: Set timeout 30000
2022-08-02 17:43:28.652 [I/O dispatcher 1] DEBUG org.apache.http.headers 134 - http-outgoing-0 >> GET / HTTP/1.1
2022-08-02 17:43:28.652 [I/O dispatcher 1] DEBUG org.apache.http.headers 137 - http-outgoing-0 >> X-Elastic-Client-Meta: es=7.17.4p,jv=1.8,t=7.17.4p,hc=4.1.5
2022-08-02 17:43:28.652 [I/O dispatcher 1] DEBUG org.apache.http.headers 137 - http-outgoing-0 >> Content-Length: 0
2022-08-02 17:43:28.652 [I/O dispatcher 1] DEBUG org.apache.http.headers 137 - http-outgoing-0 >> Host: elasticsearch-xxx.com:443
2022-08-02 17:43:28.652 [I/O dispatcher 1] DEBUG org.apache.http.headers 137 - http-outgoing-0 >> Connection: Keep-Alive
2022-08-02 17:43:28.652 [I/O dispatcher 1] DEBUG org.apache.http.headers 137 - http-outgoing-0 >> User-Agent: elasticsearch-java/7.17.4-SNAPSHOT (Java/1.8.0_292)
2022-08-02 17:43:28.652 [I/O dispatcher 1] DEBUG org.apache.http.headers 137 - http-outgoing-0 >> Authorization: Basic secret
2022-08-02 17:43:28.653 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl 108 - http-outgoing-0 10.234.8.18:39418<->103.74.51.222:443[ACTIVE][rw:][ACTIVE][rw][NEED_UNWRAP][0][0][311]: Event set [w]
2022-08-02 17:43:28.654 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.MainClientExec 273 - [exchange: 1] Request completed
2022-08-02 17:43:28.726 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl 222 - http-outgoing-0 10.234.8.18:39418<->103.74.51.222:443[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][334]: 305 bytes written
2022-08-02 17:43:28.726 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 >> "GET / HTTP/1.1[\r][\n]"
2022-08-02 17:43:28.726 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 >> "X-Elastic-Client-Meta: es=7.17.4p,jv=1.8,t=7.17.4p,hc=4.1.5[\r][\n]"
2022-08-02 17:43:28.727 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 >> "Content-Length: 0[\r][\n]"
2022-08-02 17:43:28.727 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 >> "Host: elasticsearch-xxx.com:443[\r][\n]"
2022-08-02 17:43:28.727 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
2022-08-02 17:43:28.727 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 >> "User-Agent: elasticsearch-java/7.17.4-SNAPSHOT (Java/1.8.0_292)[\r][\n]"
2022-08-02 17:43:28.727 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 >> "Authorization: Basic secret[\r][\n]"
2022-08-02 17:43:28.727 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 >> "[\r][\n]"
2022-08-02 17:43:28.727 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.InternalIODispatch 71 - http-outgoing-0 [ACTIVE] Request ready
2022-08-02 17:43:28.727 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl 116 - http-outgoing-0 10.234.8.18:39418<->103.74.51.222:443[ACTIVE][r:w][ACTIVE][r][NOT_HANDSHAKING][0][0][0]: Event cleared [w]
2022-08-02 17:43:28.732 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl 206 - http-outgoing-0 10.234.8.18:39418<->103.74.51.222:443[ACTIVE][r:r][ACTIVE][r][NOT_HANDSHAKING][0][0][0]: 698 bytes read
2022-08-02 17:43:28.732 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "HTTP/1.1 200 OK[\r][\n]"
2022-08-02 17:43:28.732 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "Server: YDWS[\r][\n]"
2022-08-02 17:43:28.732 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "Date: Tue, 02 Aug 2022 09:43:28 GMT[\r][\n]"
2022-08-02 17:43:28.732 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "Content-Type: application/json; charset=UTF-8[\r][\n]"
2022-08-02 17:43:28.732 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "Content-Length: 536[\r][\n]"
2022-08-02 17:43:28.732 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "Connection: keep-alive[\r][\n]"
2022-08-02 17:43:28.732 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "[\r][\n]"
2022-08-02 17:43:28.732 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "{[\n]"
2022-08-02 17:43:28.732 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "  "name" : "es-ad-es-node-2",[\n]"
2022-08-02 17:43:28.733 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "  "cluster_name" : "es-ad",[\n]"
2022-08-02 17:43:28.733 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "  "cluster_uuid" : "z6oA-NW_ShmpJJQSXeyOIQ",[\n]"
2022-08-02 17:43:28.733 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "  "version" : {[\n]"
2022-08-02 17:43:28.733 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "    "number" : "7.11.2",[\n]"
2022-08-02 17:43:28.733 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "    "build_flavor" : "default",[\n]"
2022-08-02 17:43:28.733 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "    "build_type" : "docker",[\n]"
2022-08-02 17:43:28.733 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "    "build_hash" : "3e5a16cfec50876d20ea77b075070932c6464c7d",[\n]"
2022-08-02 17:43:28.733 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "    "build_date" : "2021-03-06T05:54:38.141101Z",[\n]"
2022-08-02 17:43:28.733 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "    "build_snapshot" : false,[\n]"
2022-08-02 17:43:28.734 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "    "lucene_version" : "8.7.0",[\n]"
2022-08-02 17:43:28.734 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "    "minimum_wire_compatibility_version" : "6.8.0",[\n]"
2022-08-02 17:43:28.734 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "    "minimum_index_compatibility_version" : "6.0.0-beta1"[\n]"
2022-08-02 17:43:28.734 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "  },[\n]"
2022-08-02 17:43:28.734 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "  "tagline" : "You Know, for Search"[\n]"
2022-08-02 17:43:28.734 [I/O dispatcher 1] DEBUG org.apache.http.wire 54 - http-outgoing-0 << "}[\n]"
2022-08-02 17:43:28.736 [I/O dispatcher 1] DEBUG org.apache.http.headers 123 - http-outgoing-0 << HTTP/1.1 200 OK
2022-08-02 17:43:28.736 [I/O dispatcher 1] DEBUG org.apache.http.headers 126 - http-outgoing-0 << Server: YDWS
2022-08-02 17:43:28.736 [I/O dispatcher 1] DEBUG org.apache.http.headers 126 - http-outgoing-0 << Date: Tue, 02 Aug 2022 09:43:28 GMT
2022-08-02 17:43:28.736 [I/O dispatcher 1] DEBUG org.apache.http.headers 126 - http-outgoing-0 << Content-Type: application/json; charset=UTF-8
2022-08-02 17:43:28.736 [I/O dispatcher 1] DEBUG org.apache.http.headers 126 - http-outgoing-0 << Content-Length: 536
2022-08-02 17:43:28.736 [I/O dispatcher 1] DEBUG org.apache.http.headers 126 - http-outgoing-0 << Connection: keep-alive
2022-08-02 17:43:28.736 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.InternalIODispatch 106 - http-outgoing-0 [ACTIVE(536)] Response received
2022-08-02 17:43:28.737 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.MainClientExec 286 - [exchange: 1] Response received HTTP/1.1 200 OK
2022-08-02 17:43:28.739 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.InternalIODispatch 81 - http-outgoing-0 [ACTIVE(536)] Input ready
2022-08-02 17:43:28.740 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.MainClientExec 325 - [exchange: 1] Consume content
2022-08-02 17:43:28.741 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.InternalHttpAsyncClient 300 - [exchange: 1] Connection can be kept alive indefinitely
2022-08-02 17:43:28.741 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.MainClientExec 385 - [exchange: 1] Response processed
2022-08-02 17:43:28.741 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.InternalHttpAsyncClient 241 - [exchange: 1] releasing connection

Any suggestion would be appreciated.

Plus: not only save requests stuck here, search requests(eg: findById in spring data es) also stuck at the same line.

CodePudding user response：

I solved the problem finally... spring data elasticsearch(and java elasticsearch client itself) by default not enable keepalive support on connection between the client and elasticsearch.

This only happens on high concurrency conditions!

Here are similar links:

and spring data don't have support for config keepalive in properties, so code config must be involved:

    @Bean
    public RestClientBuilderCustomizer keepalive() {
        return new RestClientBuilderCustomizer() {
            @Override
            public void customize(RestClientBuilder builder) {

            }

            @Override
            public void customize(HttpAsyncClientBuilder builder) {
                // enable keep alive
                builder.setDefaultIOReactorConfig(IOReactorConfig.custom().setSoKeepAlive(true).build());
            }
        };
    }

I do thinks spring data or elasticsearch should enable keep by default!

Page link：https//www.codepudding.com/Enterprise/500507.html

Prev:Elasticsearch cluster on separate VM's configuration how does it work?
Next:Elasticsearch Node.js client throws parsing_exception: [parsing_exception] Reason: unknown query [qu
  • Related

About Us:  Contact Us      Terms of Service       Privacy Policy

Copyright © 2010-2023，Powered By CodePudding