# Cluster state update task **URL:** https://discuss.elastic.co/t/cluster-state-update-task/175372 **Category:** Elasticsearch **Created:** [April 4, 2019, 9:50am UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372 "2019-04-04T09:50:47Z") **Posts on this page:** 20 **Page:** 1
### Author: ![yahuu](https://avatars.discourse-cdn.com/v4/letter/y/90db22/32.png) [@yahuu](https://discuss.elastic.co/u/yahuu) #### Post date: [April 4, 2019, 9:50am UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/1 "2019-04-04T09:50:47Z")
Hello everyone, when i start up my docker containers for my ELK-Stack my Elasticsearch does take some time for some cluster state update tasks. What are these tasks doing? I only have one node and no cluster. Are they necessary as they slow down the startup tremendously. This is a example log message: [WARN][o.e.c.s.MasterService] [adzrBlG] cluster state update task [shard-started StartedShardEntry{shardId [[logstash2-2018.12][1]], allocationId [8Cj1XFgoSF6ms4q1E4Q0Bw], message [after existing store recovery; bootstrap\_history\_uuid=false]}[StartedShardEntry{shardId [[logstash2-2018.12][1]], allocationId [8Cj1XFgoSF6ms4q1E4Q0Bw], message [after existing store recovery; bootstrap\_history\_uuid=false]}], shard-started StartedShardEntry{shardId [[logstash-2019.10-02][0]], allocationId [11aBkGwjQvKAuE2IO1qMGw], message [after existing store recovery; bootstrap\_history\_uuid=false]}[StartedShardEntry{shardId [[logstash-2019.10-02][0]], allocationId [11aBkGwjQvKAuE2IO1qMGw], message [after existing store recovery; bootstrap\_history\_uuid=false]}]... Thank you in advance, Yahuu ---
### Author: ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner) #### Post date: [April 4, 2019, 10:23am UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/2 "2019-04-04T10:23:39Z")
> [@yahuu](#): > > Are they necessary Yes. The particular task you quoted is starting some shards so that they can be searched, which seems important to me. But they shouldn't really take very long. Can you share the output of `GET _cluster/health`? ---
### Author: ![yahuu](https://avatars.discourse-cdn.com/v4/letter/y/90db22/32.png) [@yahuu](https://discuss.elastic.co/u/yahuu) #### Post date: [April 4, 2019, 10:42am UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/3 "2019-04-04T10:42:26Z")
Right now i restarted and the health is red { "cluster\_name" : "docker-cluster", "status" : "red", "timed\_out" : false, "number\_of\_nodes" : 1, "number\_of\_data\_nodes" : 1, "active\_primary\_shards" : 58, "active\_shards" : 58, "relocating\_shards" : 0, "initializing\_shards" : 20, "unassigned\_shards" : 95, "delayed\_unassigned\_shards" : 0, "number\_of\_pending\_tasks" : 17, "number\_of\_in\_flight\_fetch" : 0, "task\_max\_waiting\_in\_queue\_millis" : 378096, "active\_shards\_percent\_as\_number" : 33.52601156069364 } After some time the shards get assigned and the status changes to green. I feel that it takes to much time. I switched from my old node (has an older elasticsearch version) to docker and i didn't have that problem on the old node. I am unsure what the problem is. ---
### Author: ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner) #### Post date: [April 4, 2019, 10:45am UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/4 "2019-04-04T10:45:51Z")
> [@yahuu](#): > > I am unsure what the problem is. Nor I. It should not take nearly this long to start this cluster. Some tasks have been waiting longer than 6 minutes to complete. Are you using local disks for storage, or are you using something network-attached? Can you share all the logs that the node writes from when it starts until when the cluster is fully green? Use [https://gist.github.com/](https://gist.github.com/) as it'll be too large for a forum post. ---
### Author: ![yahuu](https://avatars.discourse-cdn.com/v4/letter/y/90db22/32.png) [@yahuu](https://discuss.elastic.co/u/yahuu) #### Post date: [April 4, 2019, 1:06pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/5 "2019-04-04T13:06:03Z")
I am using a local disk. Now I only started elasticsearch and kibana without logstash and the cluster state update task didn't show up again. But still it takes around 8mins for the cluster health to change to "yellow" (Yellow because in some nodes i have set replicas to 1 but i only have one node). Is that normal? Here is my logs from the startup: > Do you think it has something to do with not sufficient resources? Or maybe the size or number of shards? But i had the same size shards on my old node and it wasn't such a big problem there. Querying also takes a bit longer than before i feel like. If you need some other input let me know. ---
### Author: ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner) #### Post date: [April 4, 2019, 1:16pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/6 "2019-04-04T13:16:09Z")
> [@yahuu](#): > > But still it takes around 8mins for the cluster health to change to "yellow" (Yellow because in some nodes i have set replicas to 1 but i only have one node). > Is that normal? No, it's definitely not normal for this to take 8 minutes. I was hoping for some kind of logged message indicating what was running slowly but I see only silence for those 8 minutes. Could you add `logger.org.elasticsearch.cluster.service: TRACE` to the `elasticsearch.yml` file and restart it? That should start to tell us a bit more about what's happening in that missing time. Could you also get some thread dumps by calling `GET _nodes/hot_threads?threads=9999` a few times during those 8 minutes? The only slightly strange thing I noticed in your log was that the JVM options contain `-Xms1g`, `-Xmx1g`, `-Xmx10g` and `-Xms10g`. It's picking up the larger, `10g` values, but you probably want to get rid of the `1g` ones to avoid confusion in future. ---
### Author: ![yahuu](https://avatars.discourse-cdn.com/v4/letter/y/90db22/32.png) [@yahuu](https://discuss.elastic.co/u/yahuu) #### Post date: [April 4, 2019, 1:49pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/7 "2019-04-04T13:49:59Z")
> The only slightly strange thing I noticed in your log was that the JVM options contain `-Xms1g` , `-Xmx1g` , `-Xmx10g` and `-Xms10g` . It's picking up the larger, `10g` values, but you probably want to get rid of the `1g` ones to avoid confusion in future. Yes, i noticed that too and was a bit confused. I set it in my docker-compose.yml as environment variable. But i see it using 10g of memory. Logs with `logger.org.elasticsearch.cluster.service: TRACE` in `startup.log` I put `GET _nodes/hot_threads?threads=9999` responses in `hot_threads.txt.` > ---
### Author: ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner) #### Post date: [April 4, 2019, 2:38pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/8 "2019-04-04T14:38:06Z")
Thanks. From what I can see this looks like a normal startup: the node is busy starting up all the shards, reading data from disk etc. Can you tell us a bit more about the cluster, i.e. how many indices and shards you have, and how much data there is in total? ---
### Author: ![yahuu](https://avatars.discourse-cdn.com/v4/letter/y/90db22/32.png) [@yahuu](https://discuss.elastic.co/u/yahuu) #### Post date: [April 4, 2019, 3:59pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/9 "2019-04-04T15:59:20Z")
I actually switched from a SSD to HDD. I made some space and will switch to a SSD again and see if that may change anything. I will test it next week and update here. I have around 125GB of data. Here is my output for the indices info: > I plan to actually reindex from weekly indices to monthly indices, because I have a lot of small indices. Is that a good idea? ---
### Author: ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner) #### Post date: [April 4, 2019, 4:03pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/10 "2019-04-04T16:03:08Z")
> [@yahuu](#): > > I actually switched from a SSD to HDD. That could well explain the difference. Starting Elasticsearch can be quite I/O intensive, so I'm not surprised that a spinning disk is slower. > [@yahuu](#): > > I plan to actually reindex from weekly indices to monthly indices, because I have a lot of small indices. Is that a good idea? Yes, these indices are mostly very small, and fewer larger indices would be preferable. I also think you should consider reducing the number of shards in each index from `5` to `1`. ---
### Author: ![yahuu](https://avatars.discourse-cdn.com/v4/letter/y/90db22/32.png) [@yahuu](https://discuss.elastic.co/u/yahuu) #### Post date: [April 8, 2019, 4:23pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/11 "2019-04-08T16:23:47Z")
Thank you very much for the help so far David 😀 The SSD changed a lot. It now takes about 2-3 minutes for the node to be ready. Is that more reasonable now right? I tried to shrink my indices but ran into problems. The new index created by the shrink operation is marked as red. `GET /_cluster/allocation/explain` gave following response: ``` { "index" : "logstash-2018.35_shrinked", "shard" : 0, "primary" : true, "current_state" : "unassigned", "unassigned_info" : { "reason" : "ALLOCATION_FAILED", "at" : "2019-04-08T15:59:48.615Z", "failed_allocation_attempts" : 1, "details" : "failed shard on node [MEqShQSoRoqabapHo385Fw]: failed to create shard, failure IndexNotFoundException[no such index]", "last_allocation_status" : "no" }, "can_allocate" : "no", "allocate_explanation" : "cannot allocate because allocation is not permitted to any of the nodes", "node_allocation_decisions" : [ { "node_id" : "MEqShQSoRoqabapHo385Fw", "node_name" : "MEqShQS", "transport_address" : "172.18.0.2:9300", "node_decision" : "no", "weight_ranking" : 1, "deciders" : [ { "decider" : "max_retry", "decision" : "NO", "explanation" : "shard has exceeded the maximum number of retries [1] on failed allocation attempts - manually call [/_cluster/reroute?retry_failed=true] to retry, [unassigned_info[[reason=ALLOCATION_FAILED], at[2019-04-08T15:59:48.615Z], failed_attempts[1], delayed=false, details[failed shard on node [MEqShQSoRoqabapHo385Fw]: failed to create shard, failure IndexNotFoundException[no such index]], allocation_status[deciders_no]]]" } ] } ] } ``` This is what i found in the logs: > FileSystemException was thrown. I already retried the allocation with `POST /_cluster/reroute?retry_failed=true`. Same result. There also should be enough storage left... I am not sure what to problem is. ---
### Author: ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner) #### Post date: [April 9, 2019, 6:47am UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/12 "2019-04-09T06:47:55Z")
> [@yahuu](#): > > There also should be enough storage left... I am not sure what to problem is. Nor I: ```plaintext FileSystemException[/usr/share/elasticsearch/data/nodes/0/indices/iI_tnAUtSri2X3P-4sm18w/0/index/_7.cfs: Invalid argument ``` Sounds like _something_ went wrong reading this file, or maybe writing it, but I've never seen this before. Shrinking relies on hard-linking the index files, but most file systems support this just fine. Try deleting the shrunk index `logstash-2018.35_shrinked` and shrinking it again, and if it fails for the same reason then it'd be good if you could find the full stack trace containing that `FileSystemException` and share it here. ---
### Author: ![yahuu](https://avatars.discourse-cdn.com/v4/letter/y/90db22/32.png) [@yahuu](https://discuss.elastic.co/u/yahuu) #### Post date: [April 11, 2019, 12:46pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/13 "2019-04-11T12:46:01Z")
I tried deleting and shrink again. Also tried with other shards. The stacktrace should be at line 15+ > ---
### Author: ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner) #### Post date: [April 11, 2019, 12:54pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/14 "2019-04-11T12:54:35Z")
Thanks, at least that tells us a bit more. Does this file exist? `/usr/share/elasticsearch/data/nodes/0/indices/iI_tnAUtSri2X3P-4sm18w/0/index/_7.cfs`. Is it readable (e.g. try `sha1sum /usr/share/elasticsearch/data/nodes/0/indices/iI_tnAUtSri2X3P-4sm18w/0/index/_7.cfs`). Does `dmesg` show any kernel messages about filesystem problems? ---
### Author: ![yahuu](https://avatars.discourse-cdn.com/v4/letter/y/90db22/32.png) [@yahuu](https://discuss.elastic.co/u/yahuu) #### Post date: [April 11, 2019, 1:02pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/15 "2019-04-11T13:02:57Z")
sha1sum response: `sha1sum: /usr/share/elasticsearch/data/nodes/0/indices/iI_tnAUtSri2X3P-4sm18w/0/index/_7.cfs: No such file or directory` dmesg doesn't work right now. I'll try to fix it to see the kernel messages `dmesg: read kernel buffer failed: Operation not permitted` ---
### Author: ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner) #### Post date: [April 11, 2019, 1:06pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/16 "2019-04-11T13:06:17Z")
Oh hang on the logs you shared above are dated `2019-04-08T16:07:56,775`, a few days ago. There should be more recent messages from your later attempt at the shrink. ---
### Author: ![yahuu](https://avatars.discourse-cdn.com/v4/letter/y/90db22/32.png) [@yahuu](https://discuss.elastic.co/u/yahuu) #### Post date: [April 11, 2019, 1:08pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/17 "2019-04-11T13:08:22Z")
Yes. It is the old one but the ones from today are the same: > [2019-04-11T12:31:04,944][WARN][o.e.i.c.IndicesClusterStateService] [-BmHCz1] [[logstash-2018.35\_shrinked6][0]] marking and sending shard failed due to [failed recovery] > org.elasticsearch.indices.recovery.RecoveryFailedException: [logstash-2018.35\_shrinked6][0]: Recovery failed on {-BmHCz1}{-BmHCz1qSZ2qqCUw33JjUw}{NWDdRyRmR6Kd7\_6SNmQIUA}{172.18.0.2}{172.18.0.2:9300} > at org.elasticsearch.index.shard.IndexShard.lambda$startRecovery$12(IndexShard.java:2455) [elasticsearch-6.7.1.jar:6.7.1] > at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingRunnable.run(ThreadContext.java:681) [elasticsearch-6.7.1.jar:6.7.1] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?] > at java.lang.Thread.run(Thread.java:835) [?:?] > Caused by: org.elasticsearch.index.shard.IndexShardRecoveryException: failed to recover from local shards > at org.elasticsearch.index.shard.StoreRecovery.lambda$recoverFromLocalShards$3(StoreRecovery.java:140) ~[elasticsearch-6.7.1.jar:6.7.1] > at org.elasticsearch.index.shard.StoreRecovery.executeRecovery(StoreRecovery.java:310) ~[elasticsearch-6.7.1.jar:6.7.1] > at org.elasticsearch.index.shard.StoreRecovery.recoverFromLocalShards(StoreRecovery.java:124) ~[elasticsearch-6.7.1.jar:6.7.1] > at org.elasticsearch.index.shard.IndexShard.recoverFromLocalShards(IndexShard.java:1725) ~[elasticsearch-6.7.1.jar:6.7.1] > at org.elasticsearch.index.shard.IndexShard.lambda$startRecovery$12(IndexShard.java:2450) ~[elasticsearch-6.7.1.jar:6.7.1] > ... 4 more > Caused by: java.nio.file.FileSystemException: /usr/share/elasticsearch/data/nodes/0/indices/IrvCj5v7T1OKKdj-a1HHjg/0/index/\_7.cfs: Invalid argument > at sun.nio.fs.UnixException.translateToIOException(UnixException.java:100) ~[?:?] > at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111) ~[?:?] > at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:116) ~[?:?] > at sun.nio.fs.UnixFileSystemProvider.newFileChannel(UnixFileSystemProvider.java:182) ~[?:?] > at java.nio.channels.FileChannel.open(FileChannel.java:292) ~[?:?] > at java.nio.channels.FileChannel.open(FileChannel.java:345) ~[?:?] > at org.apache.lucene.util.IOUtils.fsync(IOUtils.java:460) ~[lucene-core-7.7.0.jar:7.7.0 8c831daf4eb41153c25ddb152501ab5bae3ea3d5 - jimczi - 2019-02-04 23:16:28] > at org.apache.lucene.store.FSDirectory.fsync(FSDirectory.java:332) ~[lucene-core-7.7.0.jar:7.7.0 8c831daf4eb41153c25ddb152501ab5bae3ea3d5 - jimczi - 2019-02-04 23:16:28] > at org.apache.lucene.store.FSDirectory.sync(FSDirectory.java:287) ~[lucene-core-7.7.0.jar:7.7.0 8c831daf4eb41153c25ddb152501ab5bae3ea3d5 - jimczi - 2019-02-04 23:16:28] > at org.apache.lucene.store.FilterDirectory.sync(FilterDirectory.java:84) ~[lucene-core-7.7.0.jar:7.7.0 8c831daf4eb41153c25ddb152501ab5bae3ea3d5 - jimczi - 2019-02-04 23:16:28] > at org.apache.lucene.store.FilterDirectory.sync(FilterDirectory.java:84) ~[lucene-core-7.7.0.jar:7.7.0 8c831daf4eb41153c25ddb152501ab5bae3ea3d5 - jimczi - 2019-02-04 23:16:28] > at org.apache.lucene.store.FilterDirectory.sync(FilterDirectory.java:84) ~[lucene-core-7.7.0.jar:7.7.0 8c831daf4eb41153c25ddb152501ab5bae3ea3d5 - jimczi - 2019-02-04 23:16:28] > at org.apache.lucene.store.FilterDirectory.sync(FilterDirectory.java:84) ~[lucene-core-7.7.0.jar:7.7.0 8c831daf4eb41153c25ddb152501ab5bae3ea3d5 - jimczi - 2019-02-04 23:16:28] > at org.apache.lucene.store.LockValidatingDirectoryWrapper.sync(LockValidatingDirectoryWrapper.java:68) ~[lucene-core-7.7.0.jar:7.7.0 8c831daf4eb41153c25ddb152501ab5bae3ea3d5 - jimczi - 2019-02-04 23:16:28] > at org.apache.lucene.index.IndexWriter.startCommit(IndexWriter.java:4824) ~[lucene-core-7.7.0.jar:7.7.0 8c831daf4eb41153c25ddb152501ab5bae3ea3d5 - jimczi - 2019-02-04 23:16:28] > at org.apache.lucene.index.IndexWriter.prepareCommitInternal(IndexWriter.java:3297) ~[lucene-core-7.7.0.jar:7.7.0 8c831daf4eb41153c25ddb152501ab5bae3ea3d5 - jimczi - 2019-02-04 23:16:28] > at org.apache.lucene.index.IndexWriter.commitInternal(IndexWriter.java:3465) ~[lucene-core-7.7.0.jar:7.7.0 8c831daf4eb41153c25ddb152501ab5bae3ea3d5 - jimczi - 2019-02-04 23:16:28] > at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:3430) ~[lucene-core-7.7.0.jar:7.7.0 8c831daf4eb41153c25ddb152501ab5bae3ea3d5 - jimczi - 2019-02-04 23:16:28] > at org.elasticsearch.index.shard.StoreRecovery.addIndices(StoreRecovery.java:189) ~[elasticsearch-6.7.1.jar:6.7.1] > at org.elasticsearch.index.shard.StoreRecovery.lambda$recoverFromLocalShards$3(StoreRecovery.java:132) ~[elasticsearch-6.7.1.jar:6.7.1] > at org.elasticsearch.index.shard.StoreRecovery.executeRecovery(StoreRecovery.java:310) ~[elasticsearch-6.7.1.jar:6.7.1] > at org.elasticsearch.index.shard.StoreRecovery.recoverFromLocalShards(StoreRecovery.java:124) ~[elasticsearch-6.7.1.jar:6.7.1] > at org.elasticsearch.index.shard.IndexShard.recoverFromLocalShards(IndexShard.java:1725) ~[elasticsearch-6.7.1.jar:6.7.1] > at org.elasticsearch.index.shard.IndexShard.lambda$startRecovery$12(IndexShard.java:2450) ~[elasticsearch-6.7.1.jar:6.7.1] > ... 4 more ---
### Author: ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner) #### Post date: [April 11, 2019, 1:09pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/18 "2019-04-11T13:09:35Z")
> [@yahuu](#): > > /usr/share/elasticsearch/data/nodes/0/indices/IrvCj5v7T1OKKdj-a1HHjg/0/index/\_7.cfs Ok, same questions about this file ```auto /usr/share/elasticsearch/data/nodes/0/indices/IrvCj5v7T1OKKdj-a1HHjg/0/index/_7.cfs ``` Does it exist? What does `stat /usr/share/elasticsearch/data/nodes/0/indices/IrvCj5v7T1OKKdj-a1HHjg/0/index/_7.cfs` say? How about `sha1sum /usr/share/elasticsearch/data/nodes/0/indices/IrvCj5v7T1OKKdj-a1HHjg/0/index/_7.cfs`? ---
### Author: ![yahuu](https://avatars.discourse-cdn.com/v4/letter/y/90db22/32.png) [@yahuu](https://discuss.elastic.co/u/yahuu) #### Post date: [April 11, 2019, 1:16pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/19 "2019-04-11T13:16:48Z")
Ah sorry about the old log... Same response again for both: No such file or directory ---
### Author: ![yahuu](https://avatars.discourse-cdn.com/v4/letter/y/90db22/32.png) [@yahuu](https://discuss.elastic.co/u/yahuu) #### Post date: [April 25, 2019, 3:07pm UTC](https://discuss.elastic.co/t/cluster-state-update-task/175372/20 "2019-04-25T15:07:03Z")
I wasn't able to resolve my problem to shrink my indices. Thank you David for your time and help anyway 🙂 However what i did is to reindex the index to a new index with one shard. [Next page](https://discuss.elastic.co/t/cluster-state-update-task/175372.md?page=2)