# Shard timeout problem on AWS **URL:** \ **Category:** Elasticsearch\ **Created:** [April 27, 2012, 7:00pm UTC](https://discuss.elastic.co/t/shard-timeout-problem-on-aws/7500 "2012-04-27T19:00:39Z")\ **Posts on this page:** 9\ **Page:** 1
**Author:** ![Craig\_Brown](https://avatars.discourse-cdn.com/v4/letter/c/ce7236/32.png) [@Craig\_Brown](https://discuss.elastic.co/u/Craig_Brown)\ **Post date:** [April 27, 2012, 7:00pm UTC](https://discuss.elastic.co/t/shard-timeout-problem-on-aws/7500/1 "2012-04-27T19:00:39Z")
While doing some large scale indexing, I run across this problem fairly often, especially when having indexed \> 200m records. This is a 2-node cluster with 1 index and 50 shards 0 replicas. Index size is ~600GB per node with 390m records currently. Each node has 4-250GB EBS volumes with the ES data spread across all 4 volumes. Each volume is 62% full. Each bulk indexing request has 10k records of ~3k each. [1]: index [documents], type [records], id [43-116530000], message [UnavailableShardsException[[documents][21] [1] shardIt, [0] active : Timeout waiting for [1m], request: org.elasticsearch.action.bulk.BulkShardRequest@2c761b38]] It looks like after this error occurs, that the master will disconnect and restart, but elects itself as master instead of reconnecting with the other node. I have to stop both nodes, and then restart to get the cluster back. I have noted similar behavior with a 4-node cluster. My basic question is: is the timeout being caused by delays in AWS, EBS, or is it more likely a result of the large index size and how Lucene handles disk I/O? Secondarily, can this situation be avoided? If disk latency is too high, can we back off/recover more gracefully? Thanks! - Craig MASTER NODE [2012-04-27 15:06:59,308][INFO][node] [Courier] {0.19.2}[7517]: started [2012-04-27 15:07:12,156][INFO][gateway] [Courier] recovered [1] indices into cluster\_state [2012-04-27 15:07:28,506][INFO][cluster.service] [Courier] added {[Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ 10.33.15.1:9300]],}, reason: zen-disco-receive(join from node[[Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/10.33.15.1:9300]]]) [2012-04-27 15:11:21,474][INFO][cluster.service] [Courier] added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- receive(join from node[[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ] [inet[/10.38.249.226:9301]]{client=true, data=false}]) [2012-04-27 16:12:51,368][INFO][cluster.service] [Courier] removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- node\_left([Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ 10.38.249.226:9301]]{client=true, data=false}) [2012-04-27 16:15:16,046][INFO][cluster.service] [Courier] added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- receive(join from node[[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ 10.38.249.226:9301]]{client=true, data=false}]) [2012-04-27 17:09:28,431][INFO][cluster.service] [Courier] removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- node\_left([Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ 10.38.249.226:9301]]{client=true, data=false}) [2012-04-27 17:11:53,985][INFO][cluster.service] [Courier] added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] {client=true, data=false},}, reason: zen-disco-receive(join from node[[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] {client=true, data=false}]) [2012-04-27 17:59:17,030][INFO][node] [Multiple Man] {0.19.2}[10023]: initializing ... [2012-04-27 17:59:17,048][INFO][plugins] [Multiple Man] loaded [], sites [bigdesk] [2012-04-27 17:59:20,068][INFO][node] [Multiple Man] {0.19.2}[10023]: initialized [2012-04-27 17:59:20,069][INFO][node] [Multiple Man] {0.19.2}[10023]: starting ... [2012-04-27 17:59:20,173][INFO][transport] [Multiple Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address {inet[/10.38.249.226:9300]} [2012-04-27 17:59:24,694][INFO][cluster.service] [Multiple Man] new\_master [Multiple Man][zQvB\_5w3Tee3rW-EJ6Iahw][inet[/ 10.38.249.226:9300]], reason: zen-disco-join (elected\_as\_master) [2012-04-27 17:59:24,727][INFO][discovery] [Multiple Man] youwhodoc/zQvB\_5w3Tee3rW-EJ6Iahw [2012-04-27 17:59:24,742][INFO][http] [Multiple Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address {inet[/10.38.249.226:9200]} [2012-04-27 17:59:24,742][INFO][node] [Multiple Man] {0.19.2}[10023]: started [2012-04-27 17:59:44,560][INFO][gateway] [Multiple Man] recovered [1] indices into cluster\_state [2012-04-27 15:07:05,713][INFO][transport] [Styx and Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address {inet[/10.33.15.1:9300]} [2012-04-27 15:07:28,517][INFO][cluster.service] [Styx and Stone] detected\_master [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ 10.38.249.226:9300]], added {[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ 10.38.249.226:9300]],}, reason: zen-disco-receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]]) [2012-04-27 15:07:28,527][INFO][discovery] [Styx and Stone] youwhodoc/1p004qNdQ8iq2cL3otF1Jg [2012-04-27 15:07:28,532][INFO][http] [Styx and Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address {inet[/10.33.15.1:9200]} [2012-04-27 15:07:28,532][INFO][node] [Styx and Stone] {0.19.2}[8991]: started [2012-04-27 15:11:21,476][INFO][cluster.service] [Styx and Stone] added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ 10.38.249.226:9300]]]) [2012-04-27 16:12:51,386][INFO][cluster.service] [Styx and Stone] removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ 10.38.249.226:9300]]]) [2012-04-27 16:15:16,050][INFO][cluster.service] [Styx and Stone] added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ 10.38.249.226:9300]]]) [2012-04-27 17:09:28,717][INFO][cluster.service] [Styx and Stone] removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ 10.38.249.226:9300]]]) [2012-04-27 17:11:53,989][INFO][cluster.service] [Styx and Stone] added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/ 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ 10.38.249.226:9300]]]) [2012-04-27 17:59:10,337][INFO][discovery.zen] [Styx and Stone] master\_left [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ 10.38.249.226:9300]]], reason [transport disconnected (with verified connect)] [2012-04-27 17:59:10,386][INFO][cluster.service] [Styx and Stone] master {new [Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ 10.33.15.1:9300]], previous [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ 10.38.249.226:9300]]}, removed {[Courier][UmhafZyUQB-r3weDCPftIQ] [inet[/10.38.249.226:9300]],}, reason: zen-disco-master\_failed ([Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]) ---
**Author:** ![Igor\_Motov](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/igor_motov/32/45193_2.png) [@Igor\_Motov](https://discuss.elastic.co/u/Igor_Motov)\ **Post date:** [April 28, 2012, 3:24am UTC](https://discuss.elastic.co/t/shard-timeout-problem-on-aws/7500/2 "2012-04-28T03:24:49Z")
There are two issues here. First - node restart and second - master discovery. In order to figure out the node restart problem, it would be useful to know which version of java you are usings. After the crash do you see any hs\_err\_pid\*.log files lying around? Do you see any messages containing phrase "killed process" in /var/log/messages, /var/log/syslog or /var/log/kern.log? The second issue might be trickier. Do you always start the first node as a master? Can you reproduce the issue by just restarting the master without waiting for it to get restarted? If you can, it would be nice to get more granular logs for discovery and cluster service by adding these lines to logging.yml. logger: discovery=TRACE cluster=TRACE You config files for both nodes might be also helpful. On Friday, April 27, 2012 3:00:39 PM UTC-4, Craig Brown wrote: > While doing some large scale indexing, I run across this problem > fairly often, especially when having indexed \> 200m records. This is a > 2-node cluster with 1 index and 50 shards 0 replicas. Index size is > ~600GB per node with 390m records currently. Each node has 4-250GB > EBS volumes with the ES data spread across all 4 volumes. Each volume > is 62% full. Each bulk indexing request has 10k records of ~3k each. > > [1]: index [documents], type [records], id [43-116530000], message > [UnavailableShardsException[[documents][21] [1] shardIt, [0] active : > Timeout waiting for [1m], request: > org.elasticsearch.action.bulk.BulkShardRequest@2c761b38]] > > It looks like after this error occurs, that the master will disconnect > and restart, but elects itself as master instead of reconnecting with > the other node. I have to stop both nodes, and then restart to get the > cluster back. I have noted similar behavior with a 4-node cluster. > > My basic question is: is the timeout being caused by delays in AWS, > EBS, or is it more likely a result of the large index size and how > Lucene handles disk I/O? > > Secondarily, can this situation be avoided? If disk latency is too > high, can we back off/recover more gracefully? > > Thanks! > > - Craig > > MASTER NODE > [2012-04-27 15:06:59,308][INFO][node] [Courier] > {0.19.2}[7517]: started > [2012-04-27 15:07:12,156][INFO][gateway] [Courier] > recovered [1] indices into cluster\_state > [2012-04-27 15:07:28,506][INFO][cluster.service] [Courier] > added {[Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > 10.33.15.1:9300]],}, reason: zen-disco-receive(join from node[[Styx > and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/10.33.15.1:9300]]]) > [2012-04-27 15:11:21,474][INFO][cluster.service] [Courier] > added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > receive(join from node[[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ] > [inet[/10.38.249.226:9301]]{client=true, data=false}]) > [2012-04-27 16:12:51,368][INFO][cluster.service] [Courier] > removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > node\_left([Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > 10.38.249.226:9301]]{client=true, data=false}) > [2012-04-27 16:15:16,046][INFO][cluster.service] [Courier] > added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > receive(join from node[[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > 10.38.249.226:9301]]{client=true, data=false}]) > [2012-04-27 17:09:28,431][INFO][cluster.service] [Courier] > removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > node\_left([Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > 10.38.249.226:9301]]{client=true, data=false}) > [2012-04-27 17:11:53,985][INFO][cluster.service] [Courier] > added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > {client=true, data=false},}, reason: zen-disco-receive(join from > node[[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > {client=true, data=false}]) > [2012-04-27 17:59:17,030][INFO][node] [Multiple > Man] {0.19.2}[10023]: initializing ... > [2012-04-27 17:59:17,048][INFO][plugins] [Multiple > Man] loaded , sites [bigdesk] > [2012-04-27 17:59:20,068][INFO][node] [Multiple > Man] {0.19.2}[10023]: initialized > [2012-04-27 17:59:20,069][INFO][node] [Multiple > Man] {0.19.2}[10023]: starting ... > [2012-04-27 17:59:20,173][INFO][transport] [Multiple > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > {inet[/10.38.249.226:9300]} > [2012-04-27 17:59:24,694][INFO][cluster.service] [Multiple > Man] new\_master [Multiple Man][zQvB\_5w3Tee3rW-EJ6Iahw][inet[/ > 10.38.249.226:9300]], reason: zen-disco-join (elected\_as\_master) > [2012-04-27 17:59:24,727][INFO][discovery] [Multiple > Man] youwhodoc/zQvB\_5w3Tee3rW-EJ6Iahw > [2012-04-27 17:59:24,742][INFO][http] [Multiple > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > {inet[/10.38.249.226:9200]} > [2012-04-27 17:59:24,742][INFO][node] [Multiple > Man] {0.19.2}[10023]: started > [2012-04-27 17:59:44,560][INFO][gateway] [Multiple > Man] recovered [1] indices into cluster\_state > > [2012-04-27 15:07:05,713][INFO][transport] [Styx and > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > {inet[/10.33.15.1:9300]} > [2012-04-27 15:07:28,517][INFO][cluster.service] [Styx and > Stone] detected\_master [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > 10.38.249.226:9300]], added {[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > 10.38.249.226:9300]],}, reason: zen-disco-receive(from master > [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]]) > [2012-04-27 15:07:28,527][INFO][discovery] [Styx and > Stone] youwhodoc/1p004qNdQ8iq2cL3otF1Jg > [2012-04-27 15:07:28,532][INFO][http] [Styx and > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > {inet[/10.33.15.1:9200]} > [2012-04-27 15:07:28,532][INFO][node] [Styx and > Stone] {0.19.2}[8991]: started > [2012-04-27 15:11:21,476][INFO][cluster.service] [Styx and > Stone] added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > 10.38.249.226:9300]]]) > [2012-04-27 16:12:51,386][INFO][cluster.service] [Styx and > Stone] removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > 10.38.249.226:9300]]]) > [2012-04-27 16:15:16,050][INFO][cluster.service] [Styx and > Stone] added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > 10.38.249.226:9300]]]) > [2012-04-27 17:09:28,717][INFO][cluster.service] [Styx and > Stone] removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > 10.38.249.226:9300]]]) > [2012-04-27 17:11:53,989][INFO][cluster.service] [Styx and > Stone] added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/ > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > 10.38.249.226:9300]]]) > [2012-04-27 17:59:10,337][INFO][discovery.zen] [Styx and > Stone] master\_left [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > 10.38.249.226:9300]]], reason [transport disconnected (with verified > connect)] > [2012-04-27 17:59:10,386][INFO][cluster.service] [Styx and > Stone] master {new [Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > 10.33.15.1:9300]], previous [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > 10.38.249.226:9300]]}, removed {[Courier][UmhafZyUQB-r3weDCPftIQ] > [inet[/10.38.249.226:9300]],}, reason: zen-disco-master\_failed > ([Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]) ---
**Author:** ![kimchy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kimchy/32/44952_2.png) [@kimchy](https://discuss.elastic.co/u/kimchy)\ **Post date:** [April 29, 2012, 5:11pm UTC](https://discuss.elastic.co/t/shard-timeout-problem-on-aws/7500/3 "2012-04-29T17:11:42Z")
To Add: It seems like your master node got restarted at 2012-04-27 17:59:17,03. Are you using the service wrapper, if so, check its service.log to see if it restarted it for some reason. 50 shards index on 2 nodes seems like a bit too much (unless you are using routing). What are the spec of the machines? How much memory have you allocated to ES JVM On Sat, Apr 28, 2012 at 6:24 AM, Igor Motov [imotov@gmail.com](mailto:imotov@gmail.com) wrote: > There are two issues here. First - node restart and second - master > discovery. > > In order to figure out the node restart problem, it would be useful to > know which version of java you are usings. After the crash do you see > any hs\_err\_pid\*.log files lying around? Do you see any messages containing > phrase "killed process" in /var/log/messages, /var/log/syslog or > /var/log/kern.log? > > The second issue might be trickier. Do you always start the first node as > a master? Can you reproduce the issue by just restarting the master without > waiting for it to get restarted? If you can, it would be nice to get more > granular logs for discovery and cluster service by adding these lines to > logging.yml. > > logger: > discovery=TRACE > cluster=TRACE > > You config files for both nodes might be also helpful. > > On Friday, April 27, 2012 3:00:39 PM UTC-4, Craig Brown wrote: > > > While doing some large scale indexing, I run across this problem > > fairly often, especially when having indexed \> 200m records. This is a > > 2-node cluster with 1 index and 50 shards 0 replicas. Index size is > > ~600GB per node with 390m records currently. Each node has 4-250GB > > EBS volumes with the ES data spread across all 4 volumes. Each volume > > is 62% full. Each bulk indexing request has 10k records of ~3k each. > > > > [1]: index [documents], type [records], id [43-116530000], message > > [UnavailableShardsException[[\*\*documents][21] [1] shardIt, [0] active : > > Timeout waiting for [1m], request: > > org.elasticsearch.action.bulk.\*\*BulkShardRequest@2c761b38]] > > > > It looks like after this error occurs, that the master will disconnect > > and restart, but elects itself as master instead of reconnecting with > > the other node. I have to stop both nodes, and then restart to get the > > cluster back. I have noted similar behavior with a 4-node cluster. > > > > My basic question is: is the timeout being caused by delays in AWS, > > EBS, or is it more likely a result of the large index size and how > > Lucene handles disk I/O? > > > > Secondarily, can this situation be avoided? If disk latency is too > > high, can we back off/recover more gracefully? > > > > Thanks! > > > > - Craig > > > > MASTER NODE > > [2012-04-27 15:06:59,308][INFO][node] [Courier] > > {0.19.2}[7517]: started > > [2012-04-27 15:07:12,156][INFO][gateway] [Courier] > > recovered [1] indices into cluster\_state > > [2012-04-27 15:07:28,506][INFO][cluster.service] [Courier] > > added {[Styx and Stone][1p004qNdQ8iq2cL3otF1Jg]**[inet[/ > > 10.33.15.1:9300]],}, reason: zen-disco-receive(join from node[[Styx > > and Stone][1p004qNdQ8iq2cL3otF1Jg]**[inet[/10.33.15.1:9300]]]) > > [2012-04-27 15:11:21,474][INFO][cluster.service] [Courier] > > added {[Summers, Gabriel][QzF5z1yGQ2K-\*\*kLESKRspwQ][inet[/ > > 10.38.249.226:9301]]{client=\*\*true, data=false},}, reason: zen-disco- > > receive(join from node[[Summers, Gabriel][QzF5z1yGQ2K-\*\*kLESKRspwQ] > > [inet[/10.38.249.226:9301]]{\*\*client=true, data=false}]) > > [2012-04-27 16:12:51,368][INFO][cluster.service] [Courier] > > removed {[Summers, Gabriel][QzF5z1yGQ2K-\*\*kLESKRspwQ][inet[/ > > 10.38.249.226:9301]]{client=\*\*true, data=false},}, reason: zen-disco- > > node\_left([Summers, Gabriel][QzF5z1yGQ2K-\*\*kLESKRspwQ][inet[/ > > 10.38.249.226:9301]]{client=\*\*true, data=false}) > > [2012-04-27 16:15:16,046][INFO][cluster.service] [Courier] > > added {[Infant Terrible][IyaA9PpDSWKJ8H-\*\*7KjlScg][inet[/ > > 10.38.249.226:9301]]{client=\*\*true, data=false},}, reason: zen-disco- > > receive(join from node[[Infant Terrible][IyaA9PpDSWKJ8H-\*\*7KjlScg][inet[/ > > > > 10.38.249.226:9301]]{client=\*\*true, data=false}]) > > [2012-04-27 17:09:28,431][INFO][cluster.service] [Courier] > > removed {[Infant Terrible][IyaA9PpDSWKJ8H-\*\*7KjlScg][inet[/ > > 10.38.249.226:9301]]{client=\*\*true, data=false},}, reason: zen-disco- > > node\_left([Infant Terrible][IyaA9PpDSWKJ8H-\*\*7KjlScg][inet[/ > > 10.38.249.226:9301]]{client=\*\*true, data=false}) > > [2012-04-27 17:11:53,985][INFO][cluster.service] [Courier] > > added {[Glamor][TZwHuJlzRE-cDB-MLKA-\*\*tw][inet[/10.38.249.226:9301]] > > {client=true, data=false},}, reason: zen-disco-receive(join from > > node[[Glamor][TZwHuJlzRE-cDB-\*\*MLKA-tw][inet[/10.38.249.226:\*\*9301[http://10.38.249.226:9301](http://10.38.249.226:9301)]] > > > > {client=true, data=false}]) > > [2012-04-27 17:59:17,030][INFO][node] [Multiple > > Man] {0.19.2}[10023]: initializing ... > > [2012-04-27 17:59:17,048][INFO][plugins] [Multiple > > Man] loaded , sites [bigdesk] > > [2012-04-27 17:59:20,068][INFO][node] [Multiple > > Man] {0.19.2}[10023]: initialized > > [2012-04-27 17:59:20,069][INFO][node] [Multiple > > Man] {0.19.2}[10023]: starting ... > > [2012-04-27 17:59:20,173][INFO][transport] [Multiple > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > {inet[/10.38.249.226:9300]} > > [2012-04-27 17:59:24,694][INFO][cluster.service] [Multiple > > Man] new\_master [Multiple Man][zQvB\_5w3Tee3rW-EJ6Iahw][\*\*inet[/ > > 10.38.249.226:9300]], reason: zen-disco-join (elected\_as\_master) > > [2012-04-27 17:59:24,727][INFO][discovery] [Multiple > > Man] youwhodoc/zQvB\_5w3Tee3rW-\*\*EJ6Iahw > > [2012-04-27 17:59:24,742][INFO][http] [Multiple > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > {inet[/10.38.249.226:9200]} > > [2012-04-27 17:59:24,742][INFO][node] [Multiple > > Man] {0.19.2}[10023]: started > > [2012-04-27 17:59:44,560][INFO][gateway] [Multiple > > Man] recovered [1] indices into cluster\_state > > > > [2012-04-27 15:07:05,713][INFO][transport] [Styx and > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > {inet[/10.33.15.1:9300]} > > [2012-04-27 15:07:28,517][INFO][cluster.service] [Styx and > > Stone] detected\_master [Courier][UmhafZyUQB-\*\*r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]], added {[Courier][UmhafZyUQB-\*\*r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]],}, reason: zen-disco-receive(from master > > [[Courier][UmhafZyUQB-\*\*r3weDCPftIQ][inet[/10.38.249.\*\*226:9300]]]) > > [2012-04-27 15:07:28,527][INFO][discovery] [Styx and > > Stone] youwhodoc/\*\*1p004qNdQ8iq2cL3otF1Jg > > [2012-04-27 15:07:28,532][INFO][http] [Styx and > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > {inet[/10.33.15.1:9200]} > > [2012-04-27 15:07:28,532][INFO][node] [Styx and > > Stone] {0.19.2}[8991]: started > > [2012-04-27 15:11:21,476][INFO][cluster.service] [Styx and > > Stone] added {[Summers, Gabriel][QzF5z1yGQ2K-\*\*kLESKRspwQ][inet[/ > > 10.38.249.226:9301]]{client=\*\*true, data=false},}, reason: zen-disco- > > receive(from master [[Courier][UmhafZyUQB-\*\*r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]]) > > [2012-04-27 16:12:51,386][INFO][cluster.service] [Styx and > > Stone] removed {[Summers, Gabriel][QzF5z1yGQ2K-\*\*kLESKRspwQ][inet[/ > > 10.38.249.226:9301]]{client=\*\*true, data=false},}, reason: zen-disco- > > receive(from master [[Courier][UmhafZyUQB-\*\*r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]]) > > [2012-04-27 16:15:16,050][INFO][cluster.service] [Styx and > > Stone] added {[Infant Terrible][IyaA9PpDSWKJ8H-\*\*7KjlScg][inet[/ > > 10.38.249.226:9301]]{client=\*\*true, data=false},}, reason: zen-disco- > > receive(from master [[Courier][UmhafZyUQB-\*\*r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]]) > > [2012-04-27 17:09:28,717][INFO][cluster.service] [Styx and > > Stone] removed {[Infant Terrible][IyaA9PpDSWKJ8H-\*\*7KjlScg][inet[/ > > 10.38.249.226:9301]]{client=\*\*true, data=false},}, reason: zen-disco- > > receive(from master [[Courier][UmhafZyUQB-\*\*r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]]) > > [2012-04-27 17:11:53,989][INFO][cluster.service] [Styx and > > Stone] added {[Glamor][TZwHuJlzRE-cDB-MLKA-\*\*tw][inet[/ > > 10.38.249.226:9301]]{client=\*\*true, data=false},}, reason: zen-disco- > > receive(from master [[Courier][UmhafZyUQB-\*\*r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]]) > > [2012-04-27 17:59:10,337][INFO][discovery.zen] [Styx and > > Stone] master\_left [[Courier][UmhafZyUQB-**r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]], reason [transport disconnected (with verified > > connect)] > > [2012-04-27 17:59:10,386][INFO][cluster.service] [Styx and > > Stone] master {new [Styx and Stone][1p004qNdQ8iq2cL3otF1Jg]**[inet[/ > > 10.33.15.1:9300]], previous [Courier][UmhafZyUQB-\*\*r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]}, removed {[Courier][UmhafZyUQB-\*\*r3weDCPftIQ] > > [inet[/10.38.249.226:9300]],}, reason: zen-disco-master\_failed > > ([Courier][UmhafZyUQB-\*\*r3weDCPftIQ][inet[/10.38.249.\*\*226:9300]]) ---
**Author:** ![Craig\_Brown](https://avatars.discourse-cdn.com/v4/letter/c/ce7236/32.png) [@Craig\_Brown](https://discuss.elastic.co/u/Craig_Brown)\ **Post date:** [April 30, 2012, 9:26pm UTC](https://discuss.elastic.co/t/shard-timeout-problem-on-aws/7500/4 "2012-04-30T21:26:01Z")
Thanks for helping. So I see some problems in var/log/messages. Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.187004] lowmem\_reserve: 0 0 3031 3031 Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200023] Node 0 Normal free:4536kB min:4616kB low:5768kB high:6924kB active\_anon:2951188kB inactive\_anon:4kB active\_file:72kB inactive\_file:1228kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:3104640kB mlocked:0kB dirty:1192kB writeback:0kB mapped:0kB shmem:68kB slab\_reclaimable:13832kB slab\_unreclaimable:15144kB kernel\_stack:1560kB pagetables:9232kB unstable:0kB bounce:0kB writeback\_tmp:0kB pages\_scanned:0 all\_unreclaimable? no Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200164] Free swap = 0kB Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200169] Total swap = 0kB Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1837040 pages RAM Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 57003 pages reserved Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1605 pages shared Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1768621 pages non-shared Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Out of memory: Kill process 7517 (java) score 688 or sacrifice child Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Killed process 7517 (java) total-vm:9783644kB, anon-rss:5104668kB, file-rss:0kB So it clearly looks like it starts swapping and the runs out completely. I don't see any hs\_err\_pid files. I added the log parameters. I'll have see if I can reproduce the problem without out re-indexing all of the data again. I have to get up over 200m records before I start seeing the problem. I'll let you know. The nodes are on AWS C1XL. High-CPU Extra Large Instance 7 GB of memory, 20 EC2 Compute Units (8 virtual cores with 2.5 EC2 Compute Units each), 1690 GB of local instance storage, 64-bit platform I have 4.5GN for ES. From the looks of this, it would likely be better to have high-mem instances instead of high-compute. - Craig On Fri, Apr 27, 2012 at 9:24 PM, Igor Motov [imotov@gmail.com](mailto:imotov@gmail.com) wrote: > There are two issues here. First - node restart and second - master > discovery. > > In order to figure out the node restart problem, it would be useful to know > which version of java you are usings. After the crash do you see > any hs\_err\_pid\*.log files lying around? Do you see any messages containing > phrase "killed process" in /var/log/messages, /var/log/syslog or > /var/log/kern.log? > > The second issue might be trickier. Do you always start the first node as a > master? Can you reproduce the issue by just restarting the master without > waiting for it to get restarted? If you can, it would be nice to get more > granular logs for discovery and cluster service by adding these lines to > logging.yml. > > logger: > discovery=TRACE > cluster=TRACE > > You config files for both nodes might be also helpful. > > On Friday, April 27, 2012 3:00:39 PM UTC-4, Craig Brown wrote: > > > While doing some large scale indexing, I run across this problem > > fairly often, especially when having indexed \> 200m records. This is a > > 2-node cluster with 1 index and 50 shards 0 replicas. Index size is > > ~600GB per node with 390m records currently. Each node has 4-250GB > > EBS volumes with the ES data spread across all 4 volumes. Each volume > > is 62% full. Each bulk indexing request has 10k records of ~3k each. > > > > [1]: index [documents], type [records], id [43-116530000], message > > [UnavailableShardsException[[documents][21] [1] shardIt, [0] active : > > Timeout waiting for [1m], request: > > org.elasticsearch.action.bulk.BulkShardRequest@2c761b38]] > > > > It looks like after this error occurs, that the master will disconnect > > and restart, but elects itself as master instead of reconnecting with > > the other node. I have to stop both nodes, and then restart to get the > > cluster back. I have noted similar behavior with a 4-node cluster. > > > > My basic question is: is the timeout being caused by delays in AWS, > > EBS, or is it more likely a result of the large index size and how > > Lucene handles disk I/O? > > > > Secondarily, can this situation be avoided? If disk latency is too > > high, can we back off/recover more gracefully? > > > > Thanks! > > > > - Craig > > > > MASTER NODE > > [2012-04-27 15:06:59,308][INFO][node] [Courier] > > {0.19.2}[7517]: started > > [2012-04-27 15:07:12,156][INFO][gateway] [Courier] > > recovered [1] indices into cluster\_state > > [2012-04-27 15:07:28,506][INFO][cluster.service] [Courier] > > added {[Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > > 10.33.15.1:9300]],}, reason: zen-disco-receive(join from node[[Styx > > and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/10.33.15.1:9300]]]) > > [2012-04-27 15:11:21,474][INFO][cluster.service] [Courier] > > added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > receive(join from node[[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ] > > [inet[/10.38.249.226:9301]]{client=true, data=false}]) > > [2012-04-27 16:12:51,368][INFO][cluster.service] [Courier] > > removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > node\_left([Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > 10.38.249.226:9301]]{client=true, data=false}) > > [2012-04-27 16:15:16,046][INFO][cluster.service] [Courier] > > added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > receive(join from node[[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > 10.38.249.226:9301]]{client=true, data=false}]) > > [2012-04-27 17:09:28,431][INFO][cluster.service] [Courier] > > removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > node\_left([Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > 10.38.249.226:9301]]{client=true, data=false}) > > [2012-04-27 17:11:53,985][INFO][cluster.service] [Courier] > > added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > > {client=true, data=false},}, reason: zen-disco-receive(join from > > node[[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > > {client=true, data=false}]) > > [2012-04-27 17:59:17,030][INFO][node] [Multiple > > Man] {0.19.2}[10023]: initializing ... > > [2012-04-27 17:59:17,048][INFO][plugins] [Multiple > > Man] loaded , sites [bigdesk] > > [2012-04-27 17:59:20,068][INFO][node] [Multiple > > Man] {0.19.2}[10023]: initialized > > [2012-04-27 17:59:20,069][INFO][node] [Multiple > > Man] {0.19.2}[10023]: starting ... > > [2012-04-27 17:59:20,173][INFO][transport] [Multiple > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > {inet[/10.38.249.226:9300]} > > [2012-04-27 17:59:24,694][INFO][cluster.service] [Multiple > > Man] new\_master [Multiple Man][zQvB\_5w3Tee3rW-EJ6Iahw][inet[/ > > 10.38.249.226:9300]], reason: zen-disco-join (elected\_as\_master) > > [2012-04-27 17:59:24,727][INFO][discovery] [Multiple > > Man] youwhodoc/zQvB\_5w3Tee3rW-EJ6Iahw > > [2012-04-27 17:59:24,742][INFO][http] [Multiple > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > {inet[/10.38.249.226:9200]} > > [2012-04-27 17:59:24,742][INFO][node] [Multiple > > Man] {0.19.2}[10023]: started > > [2012-04-27 17:59:44,560][INFO][gateway] [Multiple > > Man] recovered [1] indices into cluster\_state > > > > [2012-04-27 15:07:05,713][INFO][transport] [Styx and > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > {inet[/10.33.15.1:9300]} > > [2012-04-27 15:07:28,517][INFO][cluster.service] [Styx and > > Stone] detected\_master [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]], added {[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]],}, reason: zen-disco-receive(from master > > [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]]) > > [2012-04-27 15:07:28,527][INFO][discovery] [Styx and > > Stone] youwhodoc/1p004qNdQ8iq2cL3otF1Jg > > [2012-04-27 15:07:28,532][INFO][http] [Styx and > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > {inet[/10.33.15.1:9200]} > > [2012-04-27 15:07:28,532][INFO][node] [Styx and > > Stone] {0.19.2}[8991]: started > > [2012-04-27 15:11:21,476][INFO][cluster.service] [Styx and > > Stone] added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]]) > > [2012-04-27 16:12:51,386][INFO][cluster.service] [Styx and > > Stone] removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]]) > > [2012-04-27 16:15:16,050][INFO][cluster.service] [Styx and > > Stone] added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]]) > > [2012-04-27 17:09:28,717][INFO][cluster.service] [Styx and > > Stone] removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]]) > > [2012-04-27 17:11:53,989][INFO][cluster.service] [Styx and > > Stone] added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/ > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]]) > > [2012-04-27 17:59:10,337][INFO][discovery.zen] [Styx and > > Stone] master\_left [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]], reason [transport disconnected (with verified > > connect)] > > [2012-04-27 17:59:10,386][INFO][cluster.service] [Styx and > > Stone] master {new [Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > > 10.33.15.1:9300]], previous [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > 10.38.249.226:9300]]}, removed {[Courier][UmhafZyUQB-r3weDCPftIQ] > > [inet[/10.38.249.226:9300]],}, reason: zen-disco-master\_failed > > ([Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]) -- … CRAIG BROWN chief architect youwho, Inc. [www.youwho.com](http://www.youwho.com) T: 801.855. 0921 M: 801.913. 0939 ---
**Author:** ![Craig\_Brown](https://avatars.discourse-cdn.com/v4/letter/c/ce7236/32.png) [@Craig\_Brown](https://discuss.elastic.co/u/Craig_Brown)\ **Post date:** [April 30, 2012, 9:38pm UTC](https://discuss.elastic.co/t/shard-timeout-problem-on-aws/7500/5 "2012-04-30T21:38:28Z")
Thanks Shay! I'm using the service wrapper, but it like the service.log file is not configured correctly. The nodes are on AWS C1XL. High-CPU Extra Large Instance 7 GB of memory, 20 EC2 Compute Units (8 virtual cores with 2.5 EC2 Compute Units each), 1690 GB of local instance storage, 64-bit platform 4.5GB of ram is allocated to ES. This is what I see in the wrapper.log. STATUS | wrapper | 2012/04/27 17:59:09 | JVM received a signal SIGKILL (9). STATUS | wrapper | 2012/04/27 17:59:09 | JVM process is gone. ERROR | wrapper | 2012/04/27 17:59:09 | JVM exited unexpectedly. STATUS | wrapper | 2012/04/27 17:59:14 | Launching a JVM... INFO | jvm 2 | 2012/04/27 17:59:15 | WrapperManager: Initializing... It looks like the system is running out of swap and the kernal is killing the process. So what I'm doing, along with trying to see how far I can push ES :), is to replace a Riak cluster we have. I really like Riak and it has performed well. The real problem is that it is too opaque. It is difficult/impossible to even count the number of documents we have in a bucket with a large number of documents. We need to be able to at least count how many documents we have. I have the schema set to index on on \_id and ignore everything else. The documents are 1-3k each, but we have a lot. I was trying to see if I could squeeze all of the documents on 2 nodes to save some $$ before we go live. It seems at a minimum that we should use the high-mem nodes instead of high-compute. That selection was mostly for faster indexing. We're not using routing, assuming that GET via \_id is automatically routed. Is that not true. Is putting this many documents on 2 nodes simply a really bad idea given the purpose? Would it be better to have more shards which would create smaller lucene indexes, or less shards and larger lucence indexes? I'm assuming that more shards/ smaller lucene indexes are better. Thanks! - Craig On Sun, Apr 29, 2012 at 11:11 AM, Shay Banon [kimchy@gmail.com](mailto:kimchy@gmail.com) wrote: > To Add: > > It seems like your master node got restarted at 2012-04-27 17:59:17,03. Are > you using the service wrapper, if so, check its service.log to see if it > restarted it for some reason. > > 50 shards index on 2 nodes seems like a bit too much (unless you are using > routing). What are the spec of the machines? How much memory have you > allocated to ES JVM ---
**Author:** ![Igor\_Motov](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/igor_motov/32/45193_2.png) [@Igor\_Motov](https://discuss.elastic.co/u/Igor_Motov)\ **Post date:** [April 30, 2012, 9:40pm UTC](https://discuss.elastic.co/t/shard-timeout-problem-on-aws/7500/6 "2012-04-30T21:40:35Z")
It means that you are running out of memory on the OS level. In this situation, the process that is using most of the memory (es in your case) is getting killed. If you can reproduce it, check where memory goes. It's quite possible that with some other processes running on the system 3.5 G that you leave to the rest of the system is not enough. On Monday, April 30, 2012 5:26:01 PM UTC-4, Craig Brown wrote: > Thanks for helping. > So I see some problems in var/log/messages. > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.187004] > lowmem\_reserve: 0 0 3031 3031 > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200023] Node 0 Normal > free:4536kB min:4616kB low:5768kB high:6924kB active\_anon:2951188kB > inactive\_anon:4kB active\_file:72kB inactive\_file:1228kB > unevictable:0kB isolated(anon):0kB isolated(file):0kB > present:3104640kB mlocked:0kB dirty:1192kB writeback:0kB mapped:0kB > shmem:68kB slab\_reclaimable:13832kB slab\_unreclaimable:15144kB > kernel\_stack:1560kB pagetables:9232kB unstable:0kB bounce:0kB > writeback\_tmp:0kB pages\_scanned:0 all\_unreclaimable? no > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200164] Free swap = 0kB > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200169] Total swap = 0kB > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1837040 pages RAM > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 57003 pages > reserved > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1605 pages shared > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1768621 pages > non-shared > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Out of > memory: Kill process 7517 (java) score 688 or sacrifice child > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Killed > process 7517 (java) total-vm:9783644kB, anon-rss:5104668kB, > file-rss:0kB > > So it clearly looks like it starts swapping and the runs out > completely. I don't see any hs\_err\_pid files. > > I added the log parameters. I'll have see if I can reproduce the > problem without out re-indexing all of the data again. I have to get > up over 200m records before I start seeing the problem. I'll let you > know. > > The nodes are on AWS C1XL. > High-CPU Extra Large Instance 7 GB of memory, 20 EC2 Compute Units (8 > virtual cores with 2.5 EC2 Compute Units each), 1690 GB of local > instance storage, 64-bit platform > > I have 4.5GN for ES. From the looks of this, it would likely be better > to have high-mem instances instead of high-compute. > > - Craig > > On Fri, Apr 27, 2012 at 9:24 PM, Igor Motov [imotov@gmail.com](mailto:imotov@gmail.com) wrote: > > > There are two issues here. First - node restart and second - master > > discovery. > > > > In order to figure out the node restart problem, it would be useful to > > know > > which version of java you are usings. After the crash do you see > > any hs\_err\_pid\*.log files lying around? Do you see any messages > > containing > > phrase "killed process" in /var/log/messages, /var/log/syslog or > > /var/log/kern.log? > > > > The second issue might be trickier. Do you always start the first node > > as a > > master? Can you reproduce the issue by just restarting the master > > without > > waiting for it to get restarted? If you can, it would be nice to get > > more > > granular logs for discovery and cluster service by adding these lines to > > logging.yml. > > > > logger: > > discovery=TRACE > > cluster=TRACE > > > > You config files for both nodes might be also helpful. > > > > On Friday, April 27, 2012 3:00:39 PM UTC-4, Craig Brown wrote: > > > > > While doing some large scale indexing, I run across this problem > > > fairly often, especially when having indexed \> 200m records. This is a > > > 2-node cluster with 1 index and 50 shards 0 replicas. Index size is > > > ~600GB per node with 390m records currently. Each node has 4-250GB > > > EBS volumes with the ES data spread across all 4 volumes. Each volume > > > is 62% full. Each bulk indexing request has 10k records of ~3k each. > > > > > > [1]: index [documents], type [records], id [43-116530000], message > > > [UnavailableShardsException[[documents][21] [1] shardIt, [0] active : > > > Timeout waiting for [1m], request: > > > org.elasticsearch.action.bulk.BulkShardRequest@2c761b38]] > > > > > > It looks like after this error occurs, that the master will disconnect > > > and restart, but elects itself as master instead of reconnecting with > > > the other node. I have to stop both nodes, and then restart to get the > > > cluster back. I have noted similar behavior with a 4-node cluster. > > > > > > My basic question is: is the timeout being caused by delays in AWS, > > > EBS, or is it more likely a result of the large index size and how > > > Lucene handles disk I/O? > > > > > > Secondarily, can this situation be avoided? If disk latency is too > > > high, can we back off/recover more gracefully? > > > > > > Thanks! > > > > > > - Craig > > > > > > MASTER NODE > > > [2012-04-27 15:06:59,308][INFO][node] [Courier] > > > {0.19.2}[7517]: started > > > [2012-04-27 15:07:12,156][INFO][gateway] [Courier] > > > recovered [1] indices into cluster\_state > > > [2012-04-27 15:07:28,506][INFO][cluster.service] [Courier] > > > added {[Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > > > 10.33.15.1:9300]],}, reason: zen-disco-receive(join from node[[Styx > > > and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/10.33.15.1:9300]]]) > > > [2012-04-27 15:11:21,474][INFO][cluster.service] [Courier] > > > added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(join from node[[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ] > > > [inet[/10.38.249.226:9301]]{client=true, data=false}]) > > > [2012-04-27 16:12:51,368][INFO][cluster.service] [Courier] > > > removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > node\_left([Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false}) > > > [2012-04-27 16:15:16,046][INFO][cluster.service] [Courier] > > > added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(join from node[[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false}]) > > > [2012-04-27 17:09:28,431][INFO][cluster.service] [Courier] > > > removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > node\_left([Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false}) > > > [2012-04-27 17:11:53,985][INFO][cluster.service] [Courier] > > > added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > > > {client=true, data=false},}, reason: zen-disco-receive(join from > > > node[[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > > > {client=true, data=false}]) > > > [2012-04-27 17:59:17,030][INFO][node] [Multiple > > > Man] {0.19.2}[10023]: initializing ... > > > [2012-04-27 17:59:17,048][INFO][plugins] [Multiple > > > Man] loaded , sites [bigdesk] > > > [2012-04-27 17:59:20,068][INFO][node] [Multiple > > > Man] {0.19.2}[10023]: initialized > > > [2012-04-27 17:59:20,069][INFO][node] [Multiple > > > Man] {0.19.2}[10023]: starting ... > > > [2012-04-27 17:59:20,173][INFO][transport] [Multiple > > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > > {inet[/10.38.249.226:9300]} > > > [2012-04-27 17:59:24,694][INFO][cluster.service] [Multiple > > > Man] new\_master [Multiple Man][zQvB\_5w3Tee3rW-EJ6Iahw][inet[/ > > > 10.38.249.226:9300]], reason: zen-disco-join (elected\_as\_master) > > > [2012-04-27 17:59:24,727][INFO][discovery] [Multiple > > > Man] youwhodoc/zQvB\_5w3Tee3rW-EJ6Iahw > > > [2012-04-27 17:59:24,742][INFO][http] [Multiple > > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > > {inet[/10.38.249.226:9200]} > > > [2012-04-27 17:59:24,742][INFO][node] [Multiple > > > Man] {0.19.2}[10023]: started > > > [2012-04-27 17:59:44,560][INFO][gateway] [Multiple > > > Man] recovered [1] indices into cluster\_state > > > > > > [2012-04-27 15:07:05,713][INFO][transport] [Styx and > > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > > {inet[/10.33.15.1:9300]} > > > [2012-04-27 15:07:28,517][INFO][cluster.service] [Styx and > > > Stone] detected\_master [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]], added {[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]],}, reason: zen-disco-receive(from master > > > [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]]) > > > [2012-04-27 15:07:28,527][INFO][discovery] [Styx and > > > Stone] youwhodoc/1p004qNdQ8iq2cL3otF1Jg > > > [2012-04-27 15:07:28,532][INFO][http] [Styx and > > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > > {inet[/10.33.15.1:9200]} > > > [2012-04-27 15:07:28,532][INFO][node] [Styx and > > > Stone] {0.19.2}[8991]: started > > > [2012-04-27 15:11:21,476][INFO][cluster.service] [Styx and > > > Stone] added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]]) > > > [2012-04-27 16:12:51,386][INFO][cluster.service] [Styx and > > > Stone] removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]]) > > > [2012-04-27 16:15:16,050][INFO][cluster.service] [Styx and > > > Stone] added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]]) > > > [2012-04-27 17:09:28,717][INFO][cluster.service] [Styx and > > > Stone] removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]]) > > > [2012-04-27 17:11:53,989][INFO][cluster.service] [Styx and > > > Stone] added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]]) > > > [2012-04-27 17:59:10,337][INFO][discovery.zen] [Styx and > > > Stone] master\_left [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]], reason [transport disconnected (with verified > > > connect)] > > > [2012-04-27 17:59:10,386][INFO][cluster.service] [Styx and > > > Stone] master {new [Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > > > 10.33.15.1:9300]], previous [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]}, removed {[Courier][UmhafZyUQB-r3weDCPftIQ] > > > [inet[/10.38.249.226:9300]],}, reason: zen-disco-master\_failed > > > ([Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]) > > -- > … > CRAIG BROWN > chief architect > youwho, Inc. > > [www.youwho.com](http://www.youwho.com) > > T: 801.855. 0921 > M: 801.913. 0939 On Monday, April 30, 2012 5:26:01 PM UTC-4, Craig Brown wrote: > Thanks for helping. > So I see some problems in var/log/messages. > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.187004] > lowmem\_reserve: 0 0 3031 3031 > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200023] Node 0 Normal > free:4536kB min:4616kB low:5768kB high:6924kB active\_anon:2951188kB > inactive\_anon:4kB active\_file:72kB inactive\_file:1228kB > unevictable:0kB isolated(anon):0kB isolated(file):0kB > present:3104640kB mlocked:0kB dirty:1192kB writeback:0kB mapped:0kB > shmem:68kB slab\_reclaimable:13832kB slab\_unreclaimable:15144kB > kernel\_stack:1560kB pagetables:9232kB unstable:0kB bounce:0kB > writeback\_tmp:0kB pages\_scanned:0 all\_unreclaimable? no > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200164] Free swap = 0kB > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200169] Total swap = 0kB > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1837040 pages RAM > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 57003 pages > reserved > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1605 pages shared > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1768621 pages > non-shared > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Out of > memory: Kill process 7517 (java) score 688 or sacrifice child > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Killed > process 7517 (java) total-vm:9783644kB, anon-rss:5104668kB, > file-rss:0kB > > So it clearly looks like it starts swapping and the runs out > completely. I don't see any hs\_err\_pid files. > > I added the log parameters. I'll have see if I can reproduce the > problem without out re-indexing all of the data again. I have to get > up over 200m records before I start seeing the problem. I'll let you > know. > > The nodes are on AWS C1XL. > High-CPU Extra Large Instance 7 GB of memory, 20 EC2 Compute Units (8 > virtual cores with 2.5 EC2 Compute Units each), 1690 GB of local > instance storage, 64-bit platform > > I have 4.5GN for ES. From the looks of this, it would likely be better > to have high-mem instances instead of high-compute. > > - Craig > > On Fri, Apr 27, 2012 at 9:24 PM, Igor Motov [imotov@gmail.com](mailto:imotov@gmail.com) wrote: > > > There are two issues here. First - node restart and second - master > > discovery. > > > > In order to figure out the node restart problem, it would be useful to > > know > > which version of java you are usings. After the crash do you see > > any hs\_err\_pid\*.log files lying around? Do you see any messages > > containing > > phrase "killed process" in /var/log/messages, /var/log/syslog or > > /var/log/kern.log? > > > > The second issue might be trickier. Do you always start the first node > > as a > > master? Can you reproduce the issue by just restarting the master > > without > > waiting for it to get restarted? If you can, it would be nice to get > > more > > granular logs for discovery and cluster service by adding these lines to > > logging.yml. > > > > logger: > > discovery=TRACE > > cluster=TRACE > > > > You config files for both nodes might be also helpful. > > > > On Friday, April 27, 2012 3:00:39 PM UTC-4, Craig Brown wrote: > > > > > While doing some large scale indexing, I run across this problem > > > fairly often, especially when having indexed \> 200m records. This is a > > > 2-node cluster with 1 index and 50 shards 0 replicas. Index size is > > > ~600GB per node with 390m records currently. Each node has 4-250GB > > > EBS volumes with the ES data spread across all 4 volumes. Each volume > > > is 62% full. Each bulk indexing request has 10k records of ~3k each. > > > > > > [1]: index [documents], type [records], id [43-116530000], message > > > [UnavailableShardsException[[documents][21] [1] shardIt, [0] active : > > > Timeout waiting for [1m], request: > > > org.elasticsearch.action.bulk.BulkShardRequest@2c761b38]] > > > > > > It looks like after this error occurs, that the master will disconnect > > > and restart, but elects itself as master instead of reconnecting with > > > the other node. I have to stop both nodes, and then restart to get the > > > cluster back. I have noted similar behavior with a 4-node cluster. > > > > > > My basic question is: is the timeout being caused by delays in AWS, > > > EBS, or is it more likely a result of the large index size and how > > > Lucene handles disk I/O? > > > > > > Secondarily, can this situation be avoided? If disk latency is too > > > high, can we back off/recover more gracefully? > > > > > > Thanks! > > > > > > - Craig > > > > > > MASTER NODE > > > [2012-04-27 15:06:59,308][INFO][node] [Courier] > > > {0.19.2}[7517]: started > > > [2012-04-27 15:07:12,156][INFO][gateway] [Courier] > > > recovered [1] indices into cluster\_state > > > [2012-04-27 15:07:28,506][INFO][cluster.service] [Courier] > > > added {[Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > > > 10.33.15.1:9300]],}, reason: zen-disco-receive(join from node[[Styx > > > and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/10.33.15.1:9300]]]) > > > [2012-04-27 15:11:21,474][INFO][cluster.service] [Courier] > > > added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(join from node[[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ] > > > [inet[/10.38.249.226:9301]]{client=true, data=false}]) > > > [2012-04-27 16:12:51,368][INFO][cluster.service] [Courier] > > > removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > node\_left([Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false}) > > > [2012-04-27 16:15:16,046][INFO][cluster.service] [Courier] > > > added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(join from node[[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false}]) > > > [2012-04-27 17:09:28,431][INFO][cluster.service] [Courier] > > > removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > node\_left([Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false}) > > > [2012-04-27 17:11:53,985][INFO][cluster.service] [Courier] > > > added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > > > {client=true, data=false},}, reason: zen-disco-receive(join from > > > node[[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > > > {client=true, data=false}]) > > > [2012-04-27 17:59:17,030][INFO][node] [Multiple > > > Man] {0.19.2}[10023]: initializing ... > > > [2012-04-27 17:59:17,048][INFO][plugins] [Multiple > > > Man] loaded , sites [bigdesk] > > > [2012-04-27 17:59:20,068][INFO][node] [Multiple > > > Man] {0.19.2}[10023]: initialized > > > [2012-04-27 17:59:20,069][INFO][node] [Multiple > > > Man] {0.19.2}[10023]: starting ... > > > [2012-04-27 17:59:20,173][INFO][transport] [Multiple > > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > > {inet[/10.38.249.226:9300]} > > > [2012-04-27 17:59:24,694][INFO][cluster.service] [Multiple > > > Man] new\_master [Multiple Man][zQvB\_5w3Tee3rW-EJ6Iahw][inet[/ > > > 10.38.249.226:9300]], reason: zen-disco-join (elected\_as\_master) > > > [2012-04-27 17:59:24,727][INFO][discovery] [Multiple > > > Man] youwhodoc/zQvB\_5w3Tee3rW-EJ6Iahw > > > [2012-04-27 17:59:24,742][INFO][http] [Multiple > > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > > {inet[/10.38.249.226:9200]} > > > [2012-04-27 17:59:24,742][INFO][node] [Multiple > > > Man] {0.19.2}[10023]: started > > > [2012-04-27 17:59:44,560][INFO][gateway] [Multiple > > > Man] recovered [1] indices into cluster\_state > > > > > > [2012-04-27 15:07:05,713][INFO][transport] [Styx and > > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > > {inet[/10.33.15.1:9300]} > > > [2012-04-27 15:07:28,517][INFO][cluster.service] [Styx and > > > Stone] detected\_master [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]], added {[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]],}, reason: zen-disco-receive(from master > > > [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]]) > > > [2012-04-27 15:07:28,527][INFO][discovery] [Styx and > > > Stone] youwhodoc/1p004qNdQ8iq2cL3otF1Jg > > > [2012-04-27 15:07:28,532][INFO][http] [Styx and > > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > > {inet[/10.33.15.1:9200]} > > > [2012-04-27 15:07:28,532][INFO][node] [Styx and > > > Stone] {0.19.2}[8991]: started > > > [2012-04-27 15:11:21,476][INFO][cluster.service] [Styx and > > > Stone] added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]]) > > > [2012-04-27 16:12:51,386][INFO][cluster.service] [Styx and > > > Stone] removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]]) > > > [2012-04-27 16:15:16,050][INFO][cluster.service] [Styx and > > > Stone] added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]]) > > > [2012-04-27 17:09:28,717][INFO][cluster.service] [Styx and > > > Stone] removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]]) > > > [2012-04-27 17:11:53,989][INFO][cluster.service] [Styx and > > > Stone] added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/ > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]]) > > > [2012-04-27 17:59:10,337][INFO][discovery.zen] [Styx and > > > Stone] master\_left [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]], reason [transport disconnected (with verified > > > connect)] > > > [2012-04-27 17:59:10,386][INFO][cluster.service] [Styx and > > > Stone] master {new [Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > > > 10.33.15.1:9300]], previous [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > 10.38.249.226:9300]]}, removed {[Courier][UmhafZyUQB-r3weDCPftIQ] > > > [inet[/10.38.249.226:9300]],}, reason: zen-disco-master\_failed > > > ([Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]) > > -- > … > CRAIG BROWN > chief architect > youwho, Inc. > > [www.youwho.com](http://www.youwho.com) > > T: 801.855. 0921 > M: 801.913. 0939 ---
**Author:** ![Craig\_Brown](https://avatars.discourse-cdn.com/v4/letter/c/ce7236/32.png) [@Craig\_Brown](https://discuss.elastic.co/u/Craig_Brown)\ **Post date:** [April 30, 2012, 9:56pm UTC](https://discuss.elastic.co/t/shard-timeout-problem-on-aws/7500/7 "2012-04-30T21:56:54Z")
Ya, I'm going to try a high-mem instance and see what happens. I know better what the system is doing now, so I can watch it better. As for the node restarting and not reconnecting, it is the master node of the 2 that goes down and does not reconnect. I'll need to try to reproduce it. - Craig On Mon, Apr 30, 2012 at 3:40 PM, Igor Motov [imotov@gmail.com](mailto:imotov@gmail.com) wrote: > It means that you are running out of memory on the OS level. In this > situation, the process that is using most of the memory (es in your case) is > getting killed. If you can reproduce it, check where memory goes. It's quite > possible that with some other processes running on the system 3.5 G that you > leave to the rest of the system is not enough. > > On Monday, April 30, 2012 5:26:01 PM UTC-4, Craig Brown wrote: > > > Thanks for helping. > > So I see some problems in var/log/messages. > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.187004] > > lowmem\_reserve: 0 0 3031 3031 > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200023] Node 0 Normal > > free:4536kB min:4616kB low:5768kB high:6924kB active\_anon:2951188kB > > inactive\_anon:4kB active\_file:72kB inactive\_file:1228kB > > unevictable:0kB isolated(anon):0kB isolated(file):0kB > > present:3104640kB mlocked:0kB dirty:1192kB writeback:0kB mapped:0kB > > shmem:68kB slab\_reclaimable:13832kB slab\_unreclaimable:15144kB > > kernel\_stack:1560kB pagetables:9232kB unstable:0kB bounce:0kB > > writeback\_tmp:0kB pages\_scanned:0 all\_unreclaimable? no > > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200164] Free swap = 0kB > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200169] Total swap = 0kB > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1837040 pages RAM > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 57003 pages > > reserved > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1605 pages shared > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1768621 pages > > non-shared > > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Out of > > memory: Kill process 7517 (java) score 688 or sacrifice child > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Killed > > process 7517 (java) total-vm:9783644kB, anon-rss:5104668kB, > > file-rss:0kB > > > > So it clearly looks like it starts swapping and the runs out > > completely. I don't see any hs\_err\_pid files. > > > > I added the log parameters. I'll have see if I can reproduce the > > problem without out re-indexing all of the data again. I have to get > > up over 200m records before I start seeing the problem. I'll let you > > know. > > > > The nodes are on AWS C1XL. > > High-CPU Extra Large Instance 7 GB of memory, 20 EC2 Compute Units (8 > > virtual cores with 2.5 EC2 Compute Units each), 1690 GB of local > > instance storage, 64-bit platform > > > > I have 4.5GN for ES. From the looks of this, it would likely be better > > to have high-mem instances instead of high-compute. > > > > - Craig > > > > On Fri, Apr 27, 2012 at 9:24 PM, Igor Motov [imotov@gmail.com](mailto:imotov@gmail.com) wrote: > > > > > There are two issues here. First - node restart and second - master > > > discovery. > > > > > > In order to figure out the node restart problem, it would be useful to > > > know > > > which version of java you are usings. After the crash do you see > > > any hs\_err\_pid\*.log files lying around? Do you see any messages > > > containing > > > phrase "killed process" in /var/log/messages, /var/log/syslog or > > > /var/log/kern.log? > > > > > > The second issue might be trickier. Do you always start the first node > > > as a > > > master? Can you reproduce the issue by just restarting the master > > > without > > > waiting for it to get restarted? If you can, it would be nice to get > > > more > > > granular logs for discovery and cluster service by adding these lines to > > > logging.yml. > > > > > > logger: > > > discovery=TRACE > > > cluster=TRACE > > > > > > You config files for both nodes might be also helpful. > > > > > > On Friday, April 27, 2012 3:00:39 PM UTC-4, Craig Brown wrote: > > > > > > > While doing some large scale indexing, I run across this problem > > > > fairly often, especially when having indexed \> 200m records. This is a > > > > 2-node cluster with 1 index and 50 shards 0 replicas. Index size is > > > > ~600GB per node with 390m records currently. Each node has 4-250GB > > > > EBS volumes with the ES data spread across all 4 volumes. Each volume > > > > is 62% full. Each bulk indexing request has 10k records of ~3k each. > > > > > > > > [1]: index [documents], type [records], id [43-116530000], message > > > > [UnavailableShardsException[[documents][21] [1] shardIt, [0] active : > > > > Timeout waiting for [1m], request: > > > > org.elasticsearch.action.bulk.BulkShardRequest@2c761b38]] > > > > > > > > It looks like after this error occurs, that the master will disconnect > > > > and restart, but elects itself as master instead of reconnecting with > > > > the other node. I have to stop both nodes, and then restart to get the > > > > cluster back. I have noted similar behavior with a 4-node cluster. > > > > > > > > My basic question is: is the timeout being caused by delays in AWS, > > > > EBS, or is it more likely a result of the large index size and how > > > > Lucene handles disk I/O? > > > > > > > > Secondarily, can this situation be avoided? If disk latency is too > > > > high, can we back off/recover more gracefully? > > > > > > > > Thanks! > > > > > > > > - Craig > > > > > > > > MASTER NODE > > > > [2012-04-27 15:06:59,308][INFO][node] [Courier] > > > > {0.19.2}[7517]: started > > > > [2012-04-27 15:07:12,156][INFO][gateway] [Courier] > > > > recovered [1] indices into cluster\_state > > > > [2012-04-27 15:07:28,506][INFO][cluster.service] [Courier] > > > > added {[Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > > > > 10.33.15.1:9300]],}, reason: zen-disco-receive(join from node[[Styx > > > > and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/10.33.15.1:9300]]]) > > > > [2012-04-27 15:11:21,474][INFO][cluster.service] [Courier] > > > > added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(join from node[[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ] > > > > [inet[/10.38.249.226:9301]]{client=true, data=false}]) > > > > [2012-04-27 16:12:51,368][INFO][cluster.service] [Courier] > > > > removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > node\_left([Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false}) > > > > [2012-04-27 16:15:16,046][INFO][cluster.service] [Courier] > > > > added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(join from node[[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false}]) > > > > [2012-04-27 17:09:28,431][INFO][cluster.service] [Courier] > > > > removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > node\_left([Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false}) > > > > [2012-04-27 17:11:53,985][INFO][cluster.service] [Courier] > > > > added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > > > > {client=true, data=false},}, reason: zen-disco-receive(join from > > > > node[[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > > > > {client=true, data=false}]) > > > > [2012-04-27 17:59:17,030][INFO][node] [Multiple > > > > Man] {0.19.2}[10023]: initializing ... > > > > [2012-04-27 17:59:17,048][INFO][plugins] [Multiple > > > > Man] loaded , sites [bigdesk] > > > > [2012-04-27 17:59:20,068][INFO][node] [Multiple > > > > Man] {0.19.2}[10023]: initialized > > > > [2012-04-27 17:59:20,069][INFO][node] [Multiple > > > > Man] {0.19.2}[10023]: starting ... > > > > [2012-04-27 17:59:20,173][INFO][transport] [Multiple > > > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > > > {inet[/10.38.249.226:9300]} > > > > [2012-04-27 17:59:24,694][INFO][cluster.service] [Multiple > > > > Man] new\_master [Multiple Man][zQvB\_5w3Tee3rW-EJ6Iahw][inet[/ > > > > 10.38.249.226:9300]], reason: zen-disco-join (elected\_as\_master) > > > > [2012-04-27 17:59:24,727][INFO][discovery] [Multiple > > > > Man] youwhodoc/zQvB\_5w3Tee3rW-EJ6Iahw > > > > [2012-04-27 17:59:24,742][INFO][http] [Multiple > > > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > > > {inet[/10.38.249.226:9200]} > > > > [2012-04-27 17:59:24,742][INFO][node] [Multiple > > > > Man] {0.19.2}[10023]: started > > > > [2012-04-27 17:59:44,560][INFO][gateway] [Multiple > > > > Man] recovered [1] indices into cluster\_state > > > > > > > > [2012-04-27 15:07:05,713][INFO][transport] [Styx and > > > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > > > {inet[/10.33.15.1:9300]} > > > > [2012-04-27 15:07:28,517][INFO][cluster.service] [Styx and > > > > Stone] detected\_master [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]], added {[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]],}, reason: zen-disco-receive(from master > > > > [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]]) > > > > [2012-04-27 15:07:28,527][INFO][discovery] [Styx and > > > > Stone] youwhodoc/1p004qNdQ8iq2cL3otF1Jg > > > > [2012-04-27 15:07:28,532][INFO][http] [Styx and > > > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > > > {inet[/10.33.15.1:9200]} > > > > [2012-04-27 15:07:28,532][INFO][node] [Styx and > > > > Stone] {0.19.2}[8991]: started > > > > [2012-04-27 15:11:21,476][INFO][cluster.service] [Styx and > > > > Stone] added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]]) > > > > [2012-04-27 16:12:51,386][INFO][cluster.service] [Styx and > > > > Stone] removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]]) > > > > [2012-04-27 16:15:16,050][INFO][cluster.service] [Styx and > > > > Stone] added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]]) > > > > [2012-04-27 17:09:28,717][INFO][cluster.service] [Styx and > > > > Stone] removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]]) > > > > [2012-04-27 17:11:53,989][INFO][cluster.service] [Styx and > > > > Stone] added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]]) > > > > [2012-04-27 17:59:10,337][INFO][discovery.zen] [Styx and > > > > Stone] master\_left [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]], reason [transport disconnected (with verified > > > > connect)] > > > > [2012-04-27 17:59:10,386][INFO][cluster.service] [Styx and > > > > Stone] master {new [Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > > > > 10.33.15.1:9300]], previous [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]}, removed {[Courier][UmhafZyUQB-r3weDCPftIQ] > > > > [inet[/10.38.249.226:9300]],}, reason: zen-disco-master\_failed > > > > ([Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]) > > > > -- > > … > > CRAIG BROWN > > chief architect > > youwho, Inc. > > > > [www.youwho.com](http://www.youwho.com) > > > > T: 801.855. 0921 > > M: 801.913. 0939 > > On Monday, April 30, 2012 5:26:01 PM UTC-4, Craig Brown wrote: > > > Thanks for helping. > > So I see some problems in var/log/messages. > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.187004] > > lowmem\_reserve: 0 0 3031 3031 > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200023] Node 0 Normal > > free:4536kB min:4616kB low:5768kB high:6924kB active\_anon:2951188kB > > inactive\_anon:4kB active\_file:72kB inactive\_file:1228kB > > unevictable:0kB isolated(anon):0kB isolated(file):0kB > > present:3104640kB mlocked:0kB dirty:1192kB writeback:0kB mapped:0kB > > shmem:68kB slab\_reclaimable:13832kB slab\_unreclaimable:15144kB > > kernel\_stack:1560kB pagetables:9232kB unstable:0kB bounce:0kB > > writeback\_tmp:0kB pages\_scanned:0 all\_unreclaimable? no > > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200164] Free swap = 0kB > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200169] Total swap = 0kB > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1837040 pages RAM > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 57003 pages > > reserved > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1605 pages shared > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1768621 pages > > non-shared > > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Out of > > memory: Kill process 7517 (java) score 688 or sacrifice child > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Killed > > process 7517 (java) total-vm:9783644kB, anon-rss:5104668kB, > > file-rss:0kB > > > > So it clearly looks like it starts swapping and the runs out > > completely. I don't see any hs\_err\_pid files. > > > > I added the log parameters. I'll have see if I can reproduce the > > problem without out re-indexing all of the data again. I have to get > > up over 200m records before I start seeing the problem. I'll let you > > know. > > > > The nodes are on AWS C1XL. > > High-CPU Extra Large Instance 7 GB of memory, 20 EC2 Compute Units (8 > > virtual cores with 2.5 EC2 Compute Units each), 1690 GB of local > > instance storage, 64-bit platform > > > > I have 4.5GN for ES. From the looks of this, it would likely be better > > to have high-mem instances instead of high-compute. > > > > - Craig > > > > On Fri, Apr 27, 2012 at 9:24 PM, Igor Motov [imotov@gmail.com](mailto:imotov@gmail.com) wrote: > > > > > There are two issues here. First - node restart and second - master > > > discovery. > > > > > > In order to figure out the node restart problem, it would be useful to > > > know > > > which version of java you are usings. After the crash do you see > > > any hs\_err\_pid\*.log files lying around? Do you see any messages > > > containing > > > phrase "killed process" in /var/log/messages, /var/log/syslog or > > > /var/log/kern.log? > > > > > > The second issue might be trickier. Do you always start the first node > > > as a > > > master? Can you reproduce the issue by just restarting the master > > > without > > > waiting for it to get restarted? If you can, it would be nice to get > > > more > > > granular logs for discovery and cluster service by adding these lines to > > > logging.yml. > > > > > > logger: > > > discovery=TRACE > > > cluster=TRACE > > > > > > You config files for both nodes might be also helpful. > > > > > > On Friday, April 27, 2012 3:00:39 PM UTC-4, Craig Brown wrote: > > > > > > > While doing some large scale indexing, I run across this problem > > > > fairly often, especially when having indexed \> 200m records. This is a > > > > 2-node cluster with 1 index and 50 shards 0 replicas. Index size is > > > > ~600GB per node with 390m records currently. Each node has 4-250GB > > > > EBS volumes with the ES data spread across all 4 volumes. Each volume > > > > is 62% full. Each bulk indexing request has 10k records of ~3k each. > > > > > > > > [1]: index [documents], type [records], id [43-116530000], message > > > > [UnavailableShardsException[[documents][21] [1] shardIt, [0] active : > > > > Timeout waiting for [1m], request: > > > > org.elasticsearch.action.bulk.BulkShardRequest@2c761b38]] > > > > > > > > It looks like after this error occurs, that the master will disconnect > > > > and restart, but elects itself as master instead of reconnecting with > > > > the other node. I have to stop both nodes, and then restart to get the > > > > cluster back. I have noted similar behavior with a 4-node cluster. > > > > > > > > My basic question is: is the timeout being caused by delays in AWS, > > > > EBS, or is it more likely a result of the large index size and how > > > > Lucene handles disk I/O? > > > > > > > > Secondarily, can this situation be avoided? If disk latency is too > > > > high, can we back off/recover more gracefully? > > > > > > > > Thanks! > > > > > > > > - Craig > > > > > > > > MASTER NODE > > > > [2012-04-27 15:06:59,308][INFO][node] [Courier] > > > > {0.19.2}[7517]: started > > > > [2012-04-27 15:07:12,156][INFO][gateway] [Courier] > > > > recovered [1] indices into cluster\_state > > > > [2012-04-27 15:07:28,506][INFO][cluster.service] [Courier] > > > > added {[Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > > > > 10.33.15.1:9300]],}, reason: zen-disco-receive(join from node[[Styx > > > > and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/10.33.15.1:9300]]]) > > > > [2012-04-27 15:11:21,474][INFO][cluster.service] [Courier] > > > > added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(join from node[[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ] > > > > [inet[/10.38.249.226:9301]]{client=true, data=false}]) > > > > [2012-04-27 16:12:51,368][INFO][cluster.service] [Courier] > > > > removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > node\_left([Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false}) > > > > [2012-04-27 16:15:16,046][INFO][cluster.service] [Courier] > > > > added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(join from node[[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false}]) > > > > [2012-04-27 17:09:28,431][INFO][cluster.service] [Courier] > > > > removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > node\_left([Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false}) > > > > [2012-04-27 17:11:53,985][INFO][cluster.service] [Courier] > > > > added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > > > > {client=true, data=false},}, reason: zen-disco-receive(join from > > > > node[[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > > > > {client=true, data=false}]) > > > > [2012-04-27 17:59:17,030][INFO][node] [Multiple > > > > Man] {0.19.2}[10023]: initializing ... > > > > [2012-04-27 17:59:17,048][INFO][plugins] [Multiple > > > > Man] loaded , sites [bigdesk] > > > > [2012-04-27 17:59:20,068][INFO][node] [Multiple > > > > Man] {0.19.2}[10023]: initialized > > > > [2012-04-27 17:59:20,069][INFO][node] [Multiple > > > > Man] {0.19.2}[10023]: starting ... > > > > [2012-04-27 17:59:20,173][INFO][transport] [Multiple > > > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > > > {inet[/10.38.249.226:9300]} > > > > [2012-04-27 17:59:24,694][INFO][cluster.service] [Multiple > > > > Man] new\_master [Multiple Man][zQvB\_5w3Tee3rW-EJ6Iahw][inet[/ > > > > 10.38.249.226:9300]], reason: zen-disco-join (elected\_as\_master) > > > > [2012-04-27 17:59:24,727][INFO][discovery] [Multiple > > > > Man] youwhodoc/zQvB\_5w3Tee3rW-EJ6Iahw > > > > [2012-04-27 17:59:24,742][INFO][http] [Multiple > > > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > > > {inet[/10.38.249.226:9200]} > > > > [2012-04-27 17:59:24,742][INFO][node] [Multiple > > > > Man] {0.19.2}[10023]: started > > > > [2012-04-27 17:59:44,560][INFO][gateway] [Multiple > > > > Man] recovered [1] indices into cluster\_state > > > > > > > > [2012-04-27 15:07:05,713][INFO][transport] [Styx and > > > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > > > {inet[/10.33.15.1:9300]} > > > > [2012-04-27 15:07:28,517][INFO][cluster.service] [Styx and > > > > Stone] detected\_master [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]], added {[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]],}, reason: zen-disco-receive(from master > > > > [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]]) > > > > [2012-04-27 15:07:28,527][INFO][discovery] [Styx and > > > > Stone] youwhodoc/1p004qNdQ8iq2cL3otF1Jg > > > > [2012-04-27 15:07:28,532][INFO][http] [Styx and > > > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > > > {inet[/10.33.15.1:9200]} > > > > [2012-04-27 15:07:28,532][INFO][node] [Styx and > > > > Stone] {0.19.2}[8991]: started > > > > [2012-04-27 15:11:21,476][INFO][cluster.service] [Styx and > > > > Stone] added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]]) > > > > [2012-04-27 16:12:51,386][INFO][cluster.service] [Styx and > > > > Stone] removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]]) > > > > [2012-04-27 16:15:16,050][INFO][cluster.service] [Styx and > > > > Stone] added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]]) > > > > [2012-04-27 17:09:28,717][INFO][cluster.service] [Styx and > > > > Stone] removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]]) > > > > [2012-04-27 17:11:53,989][INFO][cluster.service] [Styx and > > > > Stone] added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/ > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]]) > > > > [2012-04-27 17:59:10,337][INFO][discovery.zen] [Styx and > > > > Stone] master\_left [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]], reason [transport disconnected (with verified > > > > connect)] > > > > [2012-04-27 17:59:10,386][INFO][cluster.service] [Styx and > > > > Stone] master {new [Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > > > > 10.33.15.1:9300]], previous [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > 10.38.249.226:9300]]}, removed {[Courier][UmhafZyUQB-r3weDCPftIQ] > > > > [inet[/10.38.249.226:9300]],}, reason: zen-disco-master\_failed > > > > ([Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]) > > > > -- > > … > > CRAIG BROWN > > chief architect > > youwho, Inc. > > > > [www.youwho.com](http://www.youwho.com) > > > > T: 801.855. 0921 > > M: 801.913. 0939 -- … CRAIG BROWN chief architect youwho, Inc. [www.youwho.com](http://www.youwho.com) T: 801.855. 0921 M: 801.913. 0939 ---
**Author:** ![Craig\_Brown](https://avatars.discourse-cdn.com/v4/letter/c/ce7236/32.png) [@Craig\_Brown](https://discuss.elastic.co/u/Craig_Brown)\ **Post date:** [May 1, 2012, 6:05pm UTC](https://discuss.elastic.co/t/shard-timeout-problem-on-aws/7500/8 "2012-05-01T18:05:58Z")
I found the clustering problem. I'm using unicast and was missing a digit on the address for the second node. It worked fine if I started node 1 first, but not second. Sorry for the trouble on that. - Craig On Mon, Apr 30, 2012 at 3:56 PM, Craig Brown [cbrown@youwho.com](mailto:cbrown@youwho.com) wrote: > Ya, I'm going to try a high-mem instance and see what happens. I know > better what the system is doing now, so I can watch it better. > > As for the node restarting and not reconnecting, it is the master node > of the 2 that goes down and does not reconnect. I'll need to try to > reproduce it. > > - Craig > > On Mon, Apr 30, 2012 at 3:40 PM, Igor Motov [imotov@gmail.com](mailto:imotov@gmail.com) wrote: > > > It means that you are running out of memory on the OS level. In this > > situation, the process that is using most of the memory (es in your case) is > > getting killed. If you can reproduce it, check where memory goes. It's quite > > possible that with some other processes running on the system 3.5 G that you > > leave to the rest of the system is not enough. > > > > On Monday, April 30, 2012 5:26:01 PM UTC-4, Craig Brown wrote: > > > > > Thanks for helping. > > > So I see some problems in var/log/messages. > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.187004] > > > lowmem\_reserve: 0 0 3031 3031 > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200023] Node 0 Normal > > > free:4536kB min:4616kB low:5768kB high:6924kB active\_anon:2951188kB > > > inactive\_anon:4kB active\_file:72kB inactive\_file:1228kB > > > unevictable:0kB isolated(anon):0kB isolated(file):0kB > > > present:3104640kB mlocked:0kB dirty:1192kB writeback:0kB mapped:0kB > > > shmem:68kB slab\_reclaimable:13832kB slab\_unreclaimable:15144kB > > > kernel\_stack:1560kB pagetables:9232kB unstable:0kB bounce:0kB > > > writeback\_tmp:0kB pages\_scanned:0 all\_unreclaimable? no > > > > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200164] Free swap = 0kB > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200169] Total swap = 0kB > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1837040 pages RAM > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 57003 pages > > > reserved > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1605 pages shared > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1768621 pages > > > non-shared > > > > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Out of > > > memory: Kill process 7517 (java) score 688 or sacrifice child > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Killed > > > process 7517 (java) total-vm:9783644kB, anon-rss:5104668kB, > > > file-rss:0kB > > > > > > So it clearly looks like it starts swapping and the runs out > > > completely. I don't see any hs\_err\_pid files. > > > > > > I added the log parameters. I'll have see if I can reproduce the > > > problem without out re-indexing all of the data again. I have to get > > > up over 200m records before I start seeing the problem. I'll let you > > > know. > > > > > > The nodes are on AWS C1XL. > > > High-CPU Extra Large Instance 7 GB of memory, 20 EC2 Compute Units (8 > > > virtual cores with 2.5 EC2 Compute Units each), 1690 GB of local > > > instance storage, 64-bit platform > > > > > > I have 4.5GN for ES. From the looks of this, it would likely be better > > > to have high-mem instances instead of high-compute. > > > > > > - Craig > > > > > > On Fri, Apr 27, 2012 at 9:24 PM, Igor Motov [imotov@gmail.com](mailto:imotov@gmail.com) wrote: > > > > > > > There are two issues here. First - node restart and second - master > > > > discovery. > > > > > > > > In order to figure out the node restart problem, it would be useful to > > > > know > > > > which version of java you are usings. After the crash do you see > > > > any hs\_err\_pid\*.log files lying around? Do you see any messages > > > > containing > > > > phrase "killed process" in /var/log/messages, /var/log/syslog or > > > > /var/log/kern.log? > > > > > > > > The second issue might be trickier. Do you always start the first node > > > > as a > > > > master? Can you reproduce the issue by just restarting the master > > > > without > > > > waiting for it to get restarted? If you can, it would be nice to get > > > > more > > > > granular logs for discovery and cluster service by adding these lines to > > > > logging.yml. > > > > > > > > logger: > > > > discovery=TRACE > > > > cluster=TRACE > > > > > > > > You config files for both nodes might be also helpful. > > > > > > > > On Friday, April 27, 2012 3:00:39 PM UTC-4, Craig Brown wrote: > > > > > > > > > While doing some large scale indexing, I run across this problem > > > > > fairly often, especially when having indexed \> 200m records. This is a > > > > > 2-node cluster with 1 index and 50 shards 0 replicas. Index size is > > > > > ~600GB per node with 390m records currently. Each node has 4-250GB > > > > > EBS volumes with the ES data spread across all 4 volumes. Each volume > > > > > is 62% full. Each bulk indexing request has 10k records of ~3k each. > > > > > > > > > > [1]: index [documents], type [records], id [43-116530000], message > > > > > [UnavailableShardsException[[documents][21] [1] shardIt, [0] active : > > > > > Timeout waiting for [1m], request: > > > > > org.elasticsearch.action.bulk.BulkShardRequest@2c761b38]] > > > > > > > > > > It looks like after this error occurs, that the master will disconnect > > > > > and restart, but elects itself as master instead of reconnecting with > > > > > the other node. I have to stop both nodes, and then restart to get the > > > > > cluster back. I have noted similar behavior with a 4-node cluster. > > > > > > > > > > My basic question is: is the timeout being caused by delays in AWS, > > > > > EBS, or is it more likely a result of the large index size and how > > > > > Lucene handles disk I/O? > > > > > > > > > > Secondarily, can this situation be avoided? If disk latency is too > > > > > high, can we back off/recover more gracefully? > > > > > > > > > > Thanks! > > > > > > > > > > - Craig > > > > > > > > > > MASTER NODE > > > > > [2012-04-27 15:06:59,308][INFO][node] [Courier] > > > > > {0.19.2}[7517]: started > > > > > [2012-04-27 15:07:12,156][INFO][gateway] [Courier] > > > > > recovered [1] indices into cluster\_state > > > > > [2012-04-27 15:07:28,506][INFO][cluster.service] [Courier] > > > > > added {[Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > > > > > 10.33.15.1:9300]],}, reason: zen-disco-receive(join from node[[Styx > > > > > and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/10.33.15.1:9300]]]) > > > > > [2012-04-27 15:11:21,474][INFO][cluster.service] [Courier] > > > > > added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > > receive(join from node[[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ] > > > > > [inet[/10.38.249.226:9301]]{client=true, data=false}]) > > > > > [2012-04-27 16:12:51,368][INFO][cluster.service] [Courier] > > > > > removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > > node\_left([Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > > 10.38.249.226:9301]]{client=true, data=false}) > > > > > [2012-04-27 16:15:16,046][INFO][cluster.service] [Courier] > > > > > added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > > receive(join from node[[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > > 10.38.249.226:9301]]{client=true, data=false}]) > > > > > [2012-04-27 17:09:28,431][INFO][cluster.service] [Courier] > > > > > removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > > node\_left([Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > > 10.38.249.226:9301]]{client=true, data=false}) > > > > > [2012-04-27 17:11:53,985][INFO][cluster.service] [Courier] > > > > > added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > > > > > {client=true, data=false},}, reason: zen-disco-receive(join from > > > > > node[[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/10.38.249.226:9301]] > > > > > {client=true, data=false}]) > > > > > [2012-04-27 17:59:17,030][INFO][node] [Multiple > > > > > Man] {0.19.2}[10023]: initializing ... > > > > > [2012-04-27 17:59:17,048][INFO][plugins] [Multiple > > > > > Man] loaded , sites [bigdesk] > > > > > [2012-04-27 17:59:20,068][INFO][node] [Multiple > > > > > Man] {0.19.2}[10023]: initialized > > > > > [2012-04-27 17:59:20,069][INFO][node] [Multiple > > > > > Man] {0.19.2}[10023]: starting ... > > > > > [2012-04-27 17:59:20,173][INFO][transport] [Multiple > > > > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > > > > {inet[/10.38.249.226:9300]} > > > > > [2012-04-27 17:59:24,694][INFO][cluster.service] [Multiple > > > > > Man] new\_master [Multiple Man][zQvB\_5w3Tee3rW-EJ6Iahw][inet[/ > > > > > 10.38.249.226:9300]], reason: zen-disco-join (elected\_as\_master) > > > > > [2012-04-27 17:59:24,727][INFO][discovery] [Multiple > > > > > Man] youwhodoc/zQvB\_5w3Tee3rW-EJ6Iahw > > > > > [2012-04-27 17:59:24,742][INFO][http] [Multiple > > > > > Man] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > > > > {inet[/10.38.249.226:9200]} > > > > > [2012-04-27 17:59:24,742][INFO][node] [Multiple > > > > > Man] {0.19.2}[10023]: started > > > > > [2012-04-27 17:59:44,560][INFO][gateway] [Multiple > > > > > Man] recovered [1] indices into cluster\_state > > > > > > > > > > [2012-04-27 15:07:05,713][INFO][transport] [Styx and > > > > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish\_address > > > > > {inet[/10.33.15.1:9300]} > > > > > [2012-04-27 15:07:28,517][INFO][cluster.service] [Styx and > > > > > Stone] detected\_master [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > > 10.38.249.226:9300]], added {[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > > 10.38.249.226:9300]],}, reason: zen-disco-receive(from master > > > > > [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]]) > > > > > [2012-04-27 15:07:28,527][INFO][discovery] [Styx and > > > > > Stone] youwhodoc/1p004qNdQ8iq2cL3otF1Jg > > > > > [2012-04-27 15:07:28,532][INFO][http] [Styx and > > > > > Stone] bound\_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish\_address > > > > > {inet[/10.33.15.1:9200]} > > > > > [2012-04-27 15:07:28,532][INFO][node] [Styx and > > > > > Stone] {0.19.2}[8991]: started > > > > > [2012-04-27 15:11:21,476][INFO][cluster.service] [Styx and > > > > > Stone] added {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > > 10.38.249.226:9300]]]) > > > > > [2012-04-27 16:12:51,386][INFO][cluster.service] [Styx and > > > > > Stone] removed {[Summers, Gabriel][QzF5z1yGQ2K-kLESKRspwQ][inet[/ > > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > > 10.38.249.226:9300]]]) > > > > > [2012-04-27 16:15:16,050][INFO][cluster.service] [Styx and > > > > > Stone] added {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > > 10.38.249.226:9300]]]) > > > > > [2012-04-27 17:09:28,717][INFO][cluster.service] [Styx and > > > > > Stone] removed {[Infant Terrible][IyaA9PpDSWKJ8H-7KjlScg][inet[/ > > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > > 10.38.249.226:9300]]]) > > > > > [2012-04-27 17:11:53,989][INFO][cluster.service] [Styx and > > > > > Stone] added {[Glamor][TZwHuJlzRE-cDB-MLKA-tw][inet[/ > > > > > 10.38.249.226:9301]]{client=true, data=false},}, reason: zen-disco- > > > > > receive(from master [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > > 10.38.249.226:9300]]]) > > > > > [2012-04-27 17:59:10,337][INFO][discovery.zen] [Styx and > > > > > Stone] master\_left [[Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > > 10.38.249.226:9300]]], reason [transport disconnected (with verified > > > > > connect)] > > > > > [2012-04-27 17:59:10,386][INFO][cluster.service] [Styx and > > > > > Stone] master {new [Styx and Stone][1p004qNdQ8iq2cL3otF1Jg][inet[/ > > > > > 10.33.15.1:9300]], previous [Courier][UmhafZyUQB-r3weDCPftIQ][inet[/ > > > > > 10.38.249.226:9300]]}, removed {[Courier][UmhafZyUQB-r3weDCPftIQ] > > > > > [inet[/10.38.249.226:9300]],}, reason: zen-disco-master\_failed > > > > > ([Courier][UmhafZyUQB-r3weDCPftIQ][inet[/10.38.249.226:9300]]) > > > > > > -- > > > … > > > CRAIG BROWN > > > chief architect > > > youwho, Inc. > > > > > > [www.youwho.com](http://www.youwho.com) > > > > > > T: 801.855. 0921 > > > M: 801.913. 0939 > > > > On Monday, April 30, 2012 5:26:01 PM UTC-4, Craig Brown wrote: > > > > > Thanks for helping. > > > So I see some problems in var/log/messages. > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.187004] > > > lowmem\_reserve: 0 0 3031 3031 > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200023] Node 0 Normal > > > free:4536kB min:4616kB low:5768kB high:6924kB active\_anon:2951188kB > > > inactive\_anon:4kB active\_file:72kB inactive\_file:1228kB > > > unevictable:0kB isolated(anon):0kB isolated(file):0kB > > > present:3104640kB mlocked:0kB dirty:1192kB writeback:0kB mapped:0kB > > > shmem:68kB slab\_reclaimable:13832kB slab\_unreclaimable:15144kB > > > kernel\_stack:1560kB pagetables:9232kB unstable:0kB bounce:0kB > > > writeback\_tmp:0kB pages\_scanned:0 all\_unreclaimable? no > > > > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200164] Free swap = 0kB > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.200169] Total swap = 0kB > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1837040 pages RAM > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 57003 pages > > > reserved > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1605 pages shared > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] 1768621 pages > > > non-shared > > > > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Out of > > > memory: Kill process 7517 (java) score 688 or sacrifice child > > > Apr 27 17:59:09 ip-10-38-249-226 kernel: [959759.201013] Killed > > > process 7517 (java) total-vm:9783644kB, anon-rss:5104668kB, > > > file-rss:0kB > > > > > > So it clearly looks like it starts swapping and the runs out > > > completely. I don't see any hs\_err\_pid files. > > > > > > I added the log parameters. I'll have see if I can reproduce the > > > problem without out re-indexing all of the data again. I have to get > > > up over 200m records before I start seeing the problem. I'll let you > > > know. > > > > > > The nodes are on AWS C1XL. > > > High-CPU Extra Large Instance 7 GB of memory, 20 EC2 Compute Units (8 > > > virtual cores with 2.5 EC2 Compute Units each), 1690 GB of local > > > instance storage, 64-bit platform > > > > > > I have 4.5GN for ES. From the looks of this, it would likely be better > > > to have high-mem instances instead of high-compute. > > > > > > - Craig > > > > > > On Fri, Apr 27, 2012 at 9:24 PM, Igor Motov [imotov@gmail.com](mailto:imotov@gmail.com) wrote: > > > > > > > There are two issues here. First - node restart and second - master > > > > discovery. > > > > > > > > In order to figure out the node restart problem, it would be useful to > > > > know > > > > which version of java you are usings. After the crash do you see > > > > any hs\_err\_pid\*.log files lying around? Do you see any messages > > > > containing > > > > phrase "killed process" in /var/log/messages, /var/log/syslog or > > > > /var/log/kern.log? > > > > > > > > The second issue might be trickier. Do you always start the first node > > > > as a > > > > master? Can you reproduce the issue by just restarting the master > > > > without > > > > waiting for it to get restarted? If you can, it would be nice to get > > > > more > > > > granular logs for discovery and cluster service by adding these lines to > > > > logging.yml. > > > > > > > > logger: > > > > discovery=TRACE > > > > cluster=TRACE > > > > > > > > You config files for both nodes might be also helpful. > > > > > > > > On Friday, April 27, 2012 3:00:39 PM UTC-4, Craig Brown wrote: > > > > > > > > > While doing some large scale indexing, I run across this problem > > > > > fairly often, especially when having indexed \> 200m records. This is a > > > > > 2-node cluster with 1 index and 50 shards 0 replicas. Index size is > > > > > ~600GB per node with 390m records currently. Each node has 4-250GB > > > > > EBS volumes with the ES data spread across all 4 volumes. Each volume > > > > > is 62% full. Each bulk indexing request has 10k records of ~3k each. > > > > > > > > > > [1]: index [documents], type [records], id [43-116530000], message > > > > > [UnavailableShardsException[[documents][21] [1] shardIt, [0] active : > > > > > Timeout waiting for [1m], request: > > > > > org.elasticsearch.action.bulk.BulkShardRequest@2c761b38]] > > > > > > > > > > It looks like after this error occurs, that the master will disconnect > > > > > and restart, but elects itself as master instead of reconnecting with > > > > > the other node. I have to stop both nodes, and then restart to get the > > > > > cluster back. I have noted similar behavior with a 4-node cluster. > > > > > > > > > > My basic question is: is the timeout being caused by delays in AWS, > > > > > EBS, or is it more likely a result of the large index size and how > > > > > Lucene handles disk I/O? > > > > > > > > > > Secondarily, can this situation be avoided? If disk latency is too > > > > > high, can we back off/recover more gracefully? > > > > > > > > > > Thanks! > > > > > > > > > > - Craig ---
**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\ **Post date:** [July 6, 2017, 3:30am UTC](https://discuss.elastic.co/t/shard-timeout-problem-on-aws/7500/9 "2017-07-06T03:30:24Z")