Elasticsearch remains unhealthy because master node doesn't think its master #19842

mkelkarbv · 2016-08-05T20:02:59Z

Elasticsearch version: 1.7.3

JVM version: openjdk version "1.8.0_65"
OpenJDK Runtime Environment (build 1.8.0_65-b17)
OpenJDK 64-Bit Server VM (build 25.65-b01, mixed mode)

OS version: Amazon linux 3.14.35-28.38.amzn1.x86_64

Description of the problem including expected versus actual behavior:
Expected behavior: elasticsearch becomes healthy.

Actual behavior: elasticsearch remains unhealthy..

If the master eligible node does not find minimum number of master eligible nodes in the cluster, then it thinks its not the master node. Even though master eligible nodes become available later, it continues to think its not master, and rejects join requests. It does not re-evaluate its master status even though minimum number of master eligible nodes become available later...

sequence of events:

the chosen master node starts and does not see other master eligible nodes. We have gateway.expected_master_nodes= 3 elasticsearch config.
The chosen master node thinks its not master...
Other master eligible nodes come up and try to contact the chosen master node, and their request s get rejected...

restarting the chosen master node does not resolve the problem. However, full cluster restart fixes it..

Steps to reproduce:

Create a ES cluster with gateway.expected_master_nodes= 3 in config with dedicated client, master and data nodes.
Make sure the chosen client node starts first, and other master eligible nodes start after it.
Start other master eligible nodes, and see how their requests get rejected...

Provide logs (if relevant):

Here are some logs that we see when this happens -

from chosen master node -

[2016-07-19 15:51:12,695][WARN ][discovery.ec2] [10-100-52-166] not enough master nodes, current nodes: {{client_bv=false, availability_zone=a, master=false},{client_bv=false, availability_zone=a, data=false, master=true},{data=false, client=true},{data=false, client=true}}

From the other master eligible nodes -

[2016-07-19 15:49:44,168][DEBUG][action.admin.cluster.health] [10-100-61-115] no known master node, scheduling a retry [2016-07-19 15:50:07,936][INFO ][discovery.ec2]failed to send join request to master [10-100-52-166][Be-E2WoeQ02g9APPaTP_AQ]{client_bv=false, availability_zone=a, data=false, master=true}], reason [RemoteTransportException[[10-100-52-166]][internal:discovery/zen/join]]; nested: ElasticsearchIllegalStateException[Node [[10-100-52-166][Be-E2WoeQ02g9APPaTP_AQ][10-100-52-166][inet[/10.100.52.166:9300]]{client_bv=false, availability_zone=a, data=false, master=true}] not master for join request from [[10-100-61-115][EMVPvC_5TACp44kIpzpxWg][10-100-61-115][inet[/10.100.61.115:9300]]{client_bv=false, availability_zone=c, data=false, master=true}]]; ], tried [3] times

[2016-07-19 15:51:59,473][DEBUG][action.admin.cluster.health] [10-100-61-115] observer: timeout notification from cluster service. timeout setting [30s], time since start [30s] [2016-07-19 15:52:08,885][INFO ][discovery.ec2 ] [10-100-61-115] failed to send join request to master [[10-100-61-166][Be-E2WoeQ02g9APPaTP_AQ][10-100-52-166][inet[/10.100.52.166:9300]]{client_bv=false, availability_zone=a, data=false, master=true}], reason [RemoteTransportException[[10-100-52-166][inet[/10.100.52.166:9300]][internal:discovery/zen/join]]; nested: ElasticsearchIllegalStateException[Node [[10-100-52-166][Be-E2WoeQ02g9APPaTP_AQ][10-100-52-166][inet[/10.100.52.166:9300]]{client_bv=false, availability_zone=a, data=false, master=true}] not master for join request from [[10-100-61-115][EMVPvC_5TACp44kIpzpxWg][10-100-61-115][inet[/10.100.61.115:9300]]{client_bv=false, availability_zone=c, data=false, master=true}]]; ], tried [3] times

The text was updated successfully, but these errors were encountered:

jasontedor · 2016-08-05T22:26:55Z

How many master-eligible nodes do you have, and what is the value of discovery.zen.minimum_master_nodes?

mkelkarbv · 2016-08-08T17:14:17Z

we have 3 master eligible nodes, and value of discovery.zen.minimum_master_nodes is 2.

jasontedor · 2016-08-09T14:47:44Z

If the master eligible node does not find minimum number of master eligible nodes in the cluster, then it thinks its not the master node. Even though master eligible nodes become available later, it continues to think its not master, and rejects join requests. It does not re-evaluate its master status even though minimum number of master eligible nodes become available later...

I don't understand this paragraph. You're speaking as if there is a single master-eligible node, but you say that you have three. Either way, if there are not at least as many master-eligible nodes available as the value of discovery.zen.minimum_master_nodes, no master-eligible can become a master, that's the point of discovery.zen.minimum_master_nodes.

The setting gateway.expected_master_nodes only controls the number of master-eligible nodes that must be visible before a node will recover its local shards, I'm not sure I see the relevance to the issue here.

mkelkarbv · 2016-08-09T15:04:49Z

OK, let me clarify. There are 3 master eligible nodes in our cluster. If for some reason the elected master node does not find other master nodes ( because they are yet to bootstrap ), then elected master node does not become master, which is expected.

But after all the master eligible nodes are bootstrapped, I would expect one of the master eligible nodes to become master and elasticsearch to become healthy automatically.... In our case this doesn't happen unless we do a full cluster restart. Do you see the problem here?

jasontedor · 2016-08-09T15:14:26Z

But after all the master eligible nodes are bootstrapped, I would expect one of the master eligible nodes to become master and elasticsearch to become healthy automatically....

Correct, that is what is suppose to happen.

In our case this doesn't happen unless we do a full cluster restart. Do you see the problem here?

This does not reproduce for me, we will need more detail. Can you provide the output of /_nodes and any relevant configuration (discovery and network settings, for example).

mkelkarbv · 2016-08-09T18:23:15Z

Here are our discovery/network settings -

discovery.zen.ping.timeout: 2m
discovery.zen.ping_timeout: 2m

discovery.zen.ping.multicast.enabled: false

discovery.zen.fd.ping_interval: 1m
discovery.zen.fd.ping_timeout: 2m
discovery.zen.fd.ping_retries: 3

discovery.type: ec2

discovery.ec2.host_type: private_ip
discovery.ec2.ping.timeout: 2m
discovery.ec2.ping_timeout: 2m
discovery.ec2.any_group: false
discovery.ec2.groups: polloi-prod-uat-concsrc-fbilai-CommonInstanceSecurityGroup-16P7AUG7HNOUC

discovery.ec2.tag.Env: bazaar
discovery.ec2.tag.Cluster: uat_polloi_concsrc_fbilai_elasticsearch

cloud.aws.region: us-east-1

Here is a log message from master node that has info on the current nodes when this happened

[2016-07-19 15:51:12,695][WARN ][discovery.ec2 ] [uat-polloi-concsrc-fbilai-es-52-166] not enough master nodes, current nodes: {[uat-polloi-concsrc-fbilai-es-54-66][VM03SLT0SdiuU8VDM_aq9g][uat-polloi-concsrc-fbilai-es-54-66][inet[/10.100.54.66:9300]]{client_bv=false, availability_zone=a, master=false},[uat-polloi-concsrc-fbilai-es-52-166][Be-E2WoeQ02g9APPaTP_AQ][uat-polloi-concsrc-fbilai-es-52-166][inet[/10.100.52.166:9300]]{client_bv=false, availability_zone=a, data=false, master=true},[polloi-node-4abb5e42][SLR3eXAhTEKgcQ1XAj0M0A][uat-polloi-concsrc-fbilai-polloi-62-175][inet[/10.100.62.175:29300]]{data=false, client=true},[polloi-node-02c28aef][ov1RsoOmR1GjVkIKe39XqQ][uat-polloi-concsrc-fbilai-polloi-57-70][inet[/10.100.57.70:29300]]{data=false, client=true},}

clintongormley · 2016-08-11T18:41:02Z

That log message lists one master-eligible node only: itself.

mkelkarbv · 2016-08-11T19:03:35Z

@clintongormley right...
Suppose that there are three master eligible nodes ( node1, node2, node3) and the discovery.zen.minimum_master_nodes is set to 2. Here is chronological sequence of events -

node1 starts up, and elects itself as master. node2 and node3 haven't bootstrapped at this point.
node1 does not discover any other master eligible nodes, so thinks that its not master....
node2 and node3 come up, and try to send join requests to node1. node1 rejects them because it thinks it its NOT the master ( however, all the other nodes in cluster still think node1 is the master)..

The log message I pasted was from step 1, where only one master eligible node is up...rest of the logs are also in the issue.

After this, the cluster remains unhealthy until manual intervention...I would expect elasticsearch to recover on its own after all master eligible nodes are bootstrapped, but it does not happen. node1 does not re-evaluate its master status, and no other master is chosen as well, and the cluster continues to remain unhealthy because master node has not been discovered...Do you see the problem here?

We have had this occur from time to time. To get the cluster out of unhealthy state, we do this

stop elasticsearch on node1.
restart elasticsearch on node2 and node 3 and wait until they try to discover node1.
start elasticsearch on node1.

In summary, the real problem is elasticsearch does not recover even after all master eligible nodes become available...

clintongormley · 2016-08-12T16:05:39Z

node1 starts up, and elects itself as master. node2 and node3 haven't bootstrapped at this point.
node1 does not discover any other master eligible nodes, so thinks that its not master....

This is incorrect. Node1 won't elect itself as master until there are enough masters available.

eg:

./bin/elasticsearch --discovery.zen.minimum_master_nodes=2

[2016-08-12 17:58:44,273][INFO ][node                     ] [Wyatt Wingfoot] version[2.2.0], pid[50298], build[8ff36d1/2016-01-27T13:32:39Z]
[2016-08-12 17:58:44,273][INFO ][node                     ] [Wyatt Wingfoot] initializing ...
[2016-08-12 17:58:44,754][INFO ][plugins                  ] [Wyatt Wingfoot] modules [lang-expression, lang-groovy], plugins [], sites []
[2016-08-12 17:58:44,774][INFO ][env                      ] [Wyatt Wingfoot] using [1] data paths, mounts [[/ (/dev/disk1)]], net usable_space [91.6gb], net total_space [232.6gb], spins? [unknown], types [hfs]
[2016-08-12 17:58:44,775][INFO ][env                      ] [Wyatt Wingfoot] heap size [990.7mb], compressed ordinary object pointers [true]
[2016-08-12 17:58:46,237][INFO ][script                   ] [Wyatt Wingfoot] compiling script file [/Users/clinton/workspace/servers/elasticsearch-2.2.0/config/scripts/test.groovy]
[2016-08-12 17:58:46,888][INFO ][node                     ] [Wyatt Wingfoot] initialized
[2016-08-12 17:58:46,889][INFO ][node                     ] [Wyatt Wingfoot] starting ...
[2016-08-12 17:58:46,955][INFO ][transport                ] [Wyatt Wingfoot] publish_address {127.0.0.1:9300}, bound_addresses {[fe80::1]:9300}, {[::1]:9300}, {127.0.0.1:9300}
[2016-08-12 17:58:46,962][INFO ][discovery                ] [Wyatt Wingfoot] elasticsearch/sLS1qPKiQ4aGrWvLQP7CEw

./bin/elasticsearch --discovery.zen.minimum_master_nodes=2

[2016-08-12 17:59:00,423][INFO ][node                     ] [Harry Osborn] version[2.2.0], pid[50310], build[8ff36d1/2016-01-27T13:32:39Z]
[2016-08-12 17:59:00,424][INFO ][node                     ] [Harry Osborn] initializing ...
[2016-08-12 17:59:00,942][INFO ][plugins                  ] [Harry Osborn] modules [lang-expression, lang-groovy], plugins [], sites []
[2016-08-12 17:59:00,962][INFO ][env                      ] [Harry Osborn] using [1] data paths, mounts [[/ (/dev/disk1)]], net usable_space [91.6gb], net total_space [232.6gb], spins? [unknown], types [hfs]
[2016-08-12 17:59:00,963][INFO ][env                      ] [Harry Osborn] heap size [990.7mb], compressed ordinary object pointers [true]
[2016-08-12 17:59:02,466][INFO ][script                   ] [Harry Osborn] compiling script file [/Users/clinton/workspace/servers/elasticsearch-2.2.0/config/scripts/test.groovy]
[2016-08-12 17:59:03,093][INFO ][node                     ] [Harry Osborn] initialized
[2016-08-12 17:59:03,093][INFO ][node                     ] [Harry Osborn] starting ...
[2016-08-12 17:59:03,169][INFO ][transport                ] [Harry Osborn] publish_address {127.0.0.1:9301}, bound_addresses {[fe80::1]:9301}, {[::1]:9301}, {127.0.0.1:9301}
[2016-08-12 17:59:03,176][INFO ][discovery                ] [Harry Osborn] elasticsearch/sba7Y2POT8SrfTb0-ZJTYA

The first node only becomes master once there are enough master-eligible nodes to satisfy the requirement:

[2016-08-12 17:59:06,230][INFO ][cluster.service          ] [Wyatt Wingfoot] new_master {Wyatt Wingfoot}{sLS1qPKiQ4aGrWvLQP7CEw}{127.0.0.1}{127.0.0.1:9300}, added {{Harry Osborn}{sba7Y2POT8SrfTb0-ZJTYA}{127.0.0.1}{127.0.0.1:9301},}, reason: zen-disco-join(elected_as_master, [1] joins received)
[2016-08-12 17:59:06,248][INFO ][cluster.service          ] [Harry Osborn] detected_master {Wyatt Wingfoot}{sLS1qPKiQ4aGrWvLQP7CEw}{127.0.0.1}{127.0.0.1:9300}, added {{Wyatt Wingfoot}{sLS1qPKiQ4aGrWvLQP7CEw}{127.0.0.1}{127.0.0.1:9300},}, reason: zen-disco-receive(from master [{Wyatt Wingfoot}{sLS1qPKiQ4aGrWvLQP7CEw}{127.0.0.1}{127.0.0.1:9300}])
[2016-08-12 17:59:06,267][INFO ][http                     ] [Harry Osborn] publish_address {127.0.0.1:9200}, bound_addresses {[fe80::1]:9200}, {[::1]:9200}, {127.0.0.1:9200}
[2016-08-12 17:59:06,268][INFO ][node                     ] [Harry Osborn] started
[2016-08-12 17:59:06,298][INFO ][http                     ] [Wyatt Wingfoot] publish_address {127.0.0.1:9201}, bound_addresses {[fe80::1]:9201}, {[::1]:9201}, {127.0.0.1:9201}
[2016-08-12 17:59:06,299][INFO ][node                     ] [Wyatt Wingfoot] started

The log message you provided shows there are not enough master nodes. So something is going wrong, but we're not seeing enough logging to understand what.

mkelkarbv · 2016-08-12T16:27:10Z

@clintongormley I do see different behavior in 1.7.3

This is what we see in the logs for Node1 -

[2016-07-19 15:51:01,722][INFO ][cluster.service ] [uat-polloi-concsrc-fbilai-es-52-166] new_master [uat-polloi-concsrc-fbilai-es-52-166][Be-E2WoeQ02g9APPaTP_AQ][uat-polloi-concsrc-fbilai-es-52-166][inet[/10.100.52.166:9300]]{client_bv=false, availability_zone=a, data=false, master=true}, reason: zen-disco-join (elected_as_master)

And then -

[2016-07-19 15:51:12,695][WARN ][discovery.ec2 ] [uat-polloi-concsrc-fbilai-es-52-166] not enough master nodes, current nodes: {[uat-polloi-concsrc-fbilai-es-54-66][VM03SLT0SdiuU8VDM_aq9g][uat-polloi-concsrc-fbilai-es-54-66][inet[/10.100.54.66:9300]]{client_bv=false, availability_zone=a, master=false},[uat-polloi-concsrc-fbilai-es-52-166][Be-E2WoeQ02g9APPaTP_AQ][uat-polloi-concsrc-fbilai-es-52-166][inet[/10.100.52.166:9300]]{client_bv=false, availability_zone=a, data=false, master=true},[polloi-node-4abb5e42][SLR3eXAhTEKgcQ1XAj0M0A][uat-polloi-concsrc-fbilai-polloi-62-175][inet[/10.100.62.175:29300]]{data=false, client=true},[polloi-node-02c28aef][ov1RsoOmR1GjVkIKe39XqQ][uat-polloi-concsrc-fbilai-polloi-57-70][inet[/10.100.57.70:29300]]{data=false, client=true},}

Note how there are no master eligible nodes currently seen...
This node somehow becomes master very briefly (11 seconds in this case), and then relinquishes its master status. But after that, no other node becomes master, and cluster remains unhealthy...

clintongormley · 2016-08-12T16:53:24Z

Ah 1.7.3! OK - you need to upgrade. SO much has changed since then. We're not going to do major rewrites to the 1.x series.

clintongormley added feedback_needed :Distributed/Discovery-Plugins Anything related to our integration plugins with EC2, GCP and Azure labels Aug 11, 2016

clintongormley closed this as completed Aug 12, 2016

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Elasticsearch remains unhealthy because master node doesn't think its master #19842

Elasticsearch remains unhealthy because master node doesn't think its master #19842

mkelkarbv commented Aug 5, 2016

jasontedor commented Aug 5, 2016

mkelkarbv commented Aug 8, 2016

jasontedor commented Aug 9, 2016

mkelkarbv commented Aug 9, 2016

jasontedor commented Aug 9, 2016

mkelkarbv commented Aug 9, 2016 •

edited

clintongormley commented Aug 11, 2016

mkelkarbv commented Aug 11, 2016 •

edited

clintongormley commented Aug 12, 2016

mkelkarbv commented Aug 12, 2016

clintongormley commented Aug 12, 2016

Elasticsearch remains unhealthy because master node doesn't think its master #19842

Elasticsearch remains unhealthy because master node doesn't think its master #19842

Comments

mkelkarbv commented Aug 5, 2016

jasontedor commented Aug 5, 2016

mkelkarbv commented Aug 8, 2016

jasontedor commented Aug 9, 2016

mkelkarbv commented Aug 9, 2016

jasontedor commented Aug 9, 2016

mkelkarbv commented Aug 9, 2016 • edited

clintongormley commented Aug 11, 2016

mkelkarbv commented Aug 11, 2016 • edited

clintongormley commented Aug 12, 2016

mkelkarbv commented Aug 12, 2016

clintongormley commented Aug 12, 2016

mkelkarbv commented Aug 9, 2016 •

edited

mkelkarbv commented Aug 11, 2016 •

edited