-
Type: Bug
-
Status: Open
-
Priority: Major
-
Resolution: Unresolved
-
Affects Version/s: 10.10
-
Fix Version/s: QualifiedToSchedule
-
Component/s: Elasticsearch
-
Tags:
The tests sometimes fail because of ES client timeout during the server startup while trying to create index.
Note that the elasticsearch node is started but the create index timeout after 30s,
it could be related to very slow disk IO or some full GC -> slave load
bin/nuxeoctl start --strict --clid=/opt/build/hudson/instance.clid 2018-10-02T01:34:09,030 WARN [main] [org.nuxeo.elasticsearch.core.ElasticSearchEmbeddedNode] Elasticsearch embedded configuration is ONLY for testing purpose. You need to create a dedicated Elasticsearch cluster for production. 2018-10-02T01:34:13,739 WARN [main] [org.elasticsearch.deprecation.common.settings.Settings] [http.enabled] setting was deprecated in Elasticsearch and will be removed in a future release! See the breaking changes documentation for the next major version. 2018-10-02T01:34:52,406 ERROR [main] [org.nuxeo.runtime.model.ComponentManager] Component service:org.nuxeo.elasticsearch.ElasticSearchComponent notification of application started failed: java.io.IOException: listener timeout after waiting for [30000] ms org.nuxeo.ecm.core.api.NuxeoException: java.io.IOException: listener timeout after waiting for [30000] ms at org.nuxeo.elasticsearch.client.ESRestClient.createIndex(ESRestClient.java:213) ~[nuxeo-elasticsearch-core-10.3-SNAPSHOT.jar:?] at org.nuxeo.elasticsearch.core.ElasticSearchAdminImpl.initIndex(ElasticSearchAdminImpl.java:458) ~[nuxeo-elasticsearch-core-10.3-SNAPSHOT.jar:?] at org.nuxeo.elasticsearch.core.ElasticSearchAdminImpl.initIndex(ElasticSearchAdminImpl.java:357) ~[nuxeo-elasticsearch-core-10.3-SNAPSHOT.jar:?] at org.nuxeo.elasticsearch.core.ElasticSearchAdminImpl.initIndex(ElasticSearchAdminImpl.java:342) ~[nuxeo-elasticsearch-core-10.3-SNAPSHOT.jar:?] at org.nuxeo.elasticsearch.core.ElasticSearchAdminImpl.initIndexes(ElasticSearchAdminImpl.java:306) ~[nuxeo-elasticsearch-core-10.3-SNAPSHOT.jar:?] at org.nuxeo.elasticsearch.core.ElasticSearchAdminImpl.initializeIndexes(ElasticSearchAdminImpl.java:189) ~[nuxeo-elasticsearch-core-10.3-SNAPSHOT.jar:?] at org.nuxeo.elasticsearch.core.ElasticSearchAdminImpl.<init>(ElasticSearchAdminImpl.java:100) ~[nuxeo-elasticsearch-core-10.3-SNAPSHOT.jar:?] at org.nuxeo.elasticsearch.ElasticSearchComponent.start(ElasticSearchComponent.java:168) ~[nuxeo-elasticsearch-core-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.model.impl.RegistrationInfoImpl.start(RegistrationInfoImpl.java:381) [nuxeo-runtime-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.model.impl.ComponentManagerImpl.startComponent(ComponentManagerImpl.java:709) [nuxeo-runtime-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.model.impl.ComponentManagerImpl.startComponents(ComponentManagerImpl.java:691) [nuxeo-runtime-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.model.impl.ComponentManagerImpl.start(ComponentManagerImpl.java:792) [nuxeo-runtime-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.osgi.OSGiRuntimeService.startComponents(OSGiRuntimeService.java:447) [nuxeo-runtime-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.osgi.OSGiRuntimeService.frameworkEvent(OSGiRuntimeService.java:462) [nuxeo-runtime-10.3-SNAPSHOT.jar:?] at org.nuxeo.osgi.OSGiAdapter.fireFrameworkEvent(OSGiAdapter.java:223) [nuxeo-runtime-osgi-10.3-SNAPSHOT.jar:?] at org.nuxeo.osgi.application.loader.FrameworkLoader.doStart(FrameworkLoader.java:225) [nuxeo-runtime-osgi-10.3-SNAPSHOT.jar:?] at org.nuxeo.osgi.application.loader.FrameworkLoader.start(FrameworkLoader.java:124) [nuxeo-runtime-osgi-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.deployment.NuxeoStarter.start(NuxeoStarter.java:124) [nuxeo-runtime-deploy-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.deployment.NuxeoStarter.contextInitialized(NuxeoStarter.java:93) [nuxeo-runtime-deploy-10.3-SNAPSHOT.jar:?] Caused by: java.io.IOException: listener timeout after waiting for [30000] ms at org.elasticsearch.client.RestClient$SyncResponseListener.get(RestClient.java:684) ~[elasticsearch-rest-client-6.3.0.jar:6.3.0] at org.elasticsearch.client.RestClient.performRequest(RestClient.java:235) ~[elasticsearch-rest-client-6.3.0.jar:6.3.0] at org.elasticsearch.client.RestClient.performRequest(RestClient.java:198) ~[elasticsearch-rest-client-6.3.0.jar:6.3.0] at org.nuxeo.elasticsearch.client.ESRestClient.createIndex(ESRestClient.java:211) ~[nuxeo-elasticsearch-core-10.3-SNAPSHOT.jar:?] 2018-10-02T01:34:54,866 WARN [elasticsearch[nuxeoNode][clusterApplierService#updateTask][T#1]] [org.elasticsearch.cluster.service.ClusterApplierService] cluster state applier task [apply cluster state (from master [master {nuxeoNode}{FVQ32L4USUaffofpe4yRYA}{-E0RehjLRwO6t0FrbDSmcw}{127.0.0.1}{127.0.0.1:9300} committed version [3] source [create-index [nuxeo-audit], cause [api]]])] took [31.9s] above the warn threshold of 30s 2018-10-02T01:34:54,866 WARN [elasticsearch[nuxeoNode][masterService#updateTask][T#1]] [org.elasticsearch.cluster.service.MasterService] cluster state update task [create-index [nuxeo-audit], cause [api]] took [32.4s] above the warn threshold of 30s 2018-10-02T01:34:54,864 ERROR [main] [org.nuxeo.runtime.model.ComponentManager] Component service:org.nuxeo.ecm.core.uidgen.UIDGeneratorService notification of application started failed: null java.lang.NullPointerException: null at org.nuxeo.elasticsearch.ElasticSearchComponent.getClient(ElasticSearchComponent.java:240) ~[nuxeo-elasticsearch-core-10.3-SNAPSHOT.jar:?] at org.nuxeo.elasticsearch.seqgen.ESUIDSequencer.init(ESUIDSequencer.java:64) ~[nuxeo-elasticsearch-seqgen-10.3-SNAPSHOT.jar:?] at org.nuxeo.ecm.core.uidgen.UIDGeneratorComponent.start(UIDGeneratorComponent.java:63) ~[nuxeo-core-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.model.impl.RegistrationInfoImpl.start(RegistrationInfoImpl.java:381) [nuxeo-runtime-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.model.impl.ComponentManagerImpl.startComponent(ComponentManagerImpl.java:709) [nuxeo-runtime-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.model.impl.ComponentManagerImpl.startComponents(ComponentManagerImpl.java:691) [nuxeo-runtime-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.model.impl.ComponentManagerImpl.start(ComponentManagerImpl.java:792) [nuxeo-runtime-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.osgi.OSGiRuntimeService.startComponents(OSGiRuntimeService.java:447) [nuxeo-runtime-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.osgi.OSGiRuntimeService.frameworkEvent(OSGiRuntimeService.java:462) [nuxeo-runtime-10.3-SNAPSHOT.jar:?] at org.nuxeo.osgi.OSGiAdapter.fireFrameworkEvent(OSGiAdapter.java:223) [nuxeo-runtime-osgi-10.3-SNAPSHOT.jar:?] at org.nuxeo.osgi.application.loader.FrameworkLoader.doStart(FrameworkLoader.java:225) [nuxeo-runtime-osgi-10.3-SNAPSHOT.jar:?] at org.nuxeo.osgi.application.loader.FrameworkLoader.start(FrameworkLoader.java:124) [nuxeo-runtime-osgi-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.deployment.NuxeoStarter.start(NuxeoStarter.java:124) [nuxeo-runtime-deploy-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.deployment.NuxeoStarter.contextInitialized(NuxeoStarter.java:93) [nuxeo-runtime-deploy-10.3-SNAPSHOT.jar:?] 2018-10-02T01:34:58,055 ERROR [main] [org.nuxeo.runtime.osgi.OSGiRuntimeService] Nuxeo Platform Started ====================================================================== = Component Loading Status: Pending: 0 / Missing: 0 / Unstarted: 3 / Total: 493 - service:org.nuxeo.ecm.core.uidgen.UIDGeneratorService - service:org.nuxeo.ecm.platform.audit.service.NXAuditEventsService - service:org.nuxeo.elasticsearch.ElasticSearchComponent
====================================================================== 2018-10-02T09:30:57,489 WARN [ElasticSearchEmbeddedNode] Elasticsearch embedded configuration is ONLY for testing purpose. You need to create a dedicated Elasticsearch cluster for production. 2018-10-02T09:30:59,892 WARN [Settings] [http.enabled] setting was deprecated in Elasticsearch and will be removed in a future release! See the breaking changes documentation for the next major version. 2018-10-02T09:31:12,318 WARN [ElasticSearchIndexingImpl] Trying to delete a non existing doc: {"id":"IxCd-15","type":"DELETE","docId":"1341611d-793a-4c94-bcdf-c72e7164ffff","path":"/document-route-models-root/SerialDocumentReview","repo":"default","recurse":true,"sync":false,"order":1538472672271007} 2018-10-02T09:31:12,319 INFO [OSGiRuntimeService] Nuxeo Platform Started ====================================================================== = Component Loading Status: Pending: 0 / Missing: 0 / Unstarted: 0 / Total: 493 ====================================================================== 2018-10-02T09:31:12,328 WARN [ElasticSearchIndexingImpl] Trying to delete a non existing doc: {"id":"IxCd-4","type":"DELETE","docId":"b294c5fc-547f-44fe-98b8-99eb12d04acd","path":"/document-route-models-root/ParallelDocumentReview","repo":"default","recurse":true,"sync":false,"order":1538472672271007} 2018-10-02 09:31:14.255 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 33352 ms
Some failed builds:
https://qa.nuxeo.org/jenkins/job/master/job/addons_FT_nuxeo-apidoc-master/1147/
https://qa.nuxeo.org/jenkins/job/master/job/addons_FT_nuxeo-wopi-master/51/
- is related to
-
NXP-23761 Increase connection timeout on Elasticsearch RestClient
- Resolved