Multiple issues following configuring shard allocation awareness and full cluster restart

Elastic Stack Elasticsearch
1

Hi,
I've encountered multiple issues after configuring shard allocation
awareness and doing a full cluster restart. From previous experience I can
say I've already seen such issues so I'm not sure if it's related to the
configuration change or the restart. It's going to be a long post so please
bare with me.

I started out with 5 servers running 0.18.5 and tried to add one additional
server using a different zone. The servers are not very busy or loaded so
one server can hold the data of the other 5. The 5 servers are connected
over fast LAN and were using multicast discovery and the new server was
connected over WAN and using unicast. I've also configured forced awareness
to make sure the data got replicated the way I wanted it to. Then restarted
the cluster servers one by one for the configuration changes to take
effect. After the restart a lot of shards remained unallocated, even after
a long time, so I've tried various things but here is a summary of the
issues:

  • Shards which are available on disk do not get loaded with message
    saying they are not there.
  • Some of the original servers didn't know the new server and said it
    wasn't a part of the cluster, this problem was mostly resolved after
    switching to full unicast configuration).
  • When the master node was taken down the other servers didn't elect a
    new master even after a very long wait. They just kept saying it was
    unreachable.
  • When the master was brought up again some servers would not connect to
    it anymore.
  • When trying to recover (using the local gateway) servers would try to
    connect to other servers and fail, usually with errors of connection
    interruption.
  • Although I have configured expected_nodes and recover_after_nodes the
    cluster would still wait the recover_after_time before starting the
    recovery even when all (or at least most) the nodes were up.

I've tried to get this to work for hours but the cluster state remained red
with many unloaded shards, eventually I gave up, wiped the entire cluster
and reindexed the data. The next day I tried adding another remote server,
in the same zone as the one added the day before and had exactly the same
problems. This time I also tried upgrading to 0.19.3 but that didn't really
improve anything, in fact it exposed some new exceptions that were not
present before. Again, after trying quite a lot to get it to work I gave up
wiped out the entire cluster and re-indexed the data.

Unfortunately I don't have the logs to support all of the above issues
because there seems to be a problem with the log rolling. It doesn't create
a new daily file but just overwrites the existing file, so all I have is
what I could scrape from open console sessions. The following exceptions
are not in any particular order, they are just random things I picked up
from my consoles but all of them happened many many times:

Index out of range exception:

[2012-05-11 05:07:58,092][WARN ][cluster.action.shard ] [es1-04]
sending failed shard for [6136561_xs][0], node[JYRwNCxDSESuFFQ5jvvSEg],
[P], s[INITIALIZING], reason [Failed to start shard, message
[IndexShardGatewayRecoveryException[[6136561_xs][0] failed to recover
shard]; nested: StringIndexOutOfBoundsException[String index out of range:
0]; ]]
[2012-05-11 05:07:58,602][WARN ][indices.cluster ] [es1-04]
[6136561_xs][0] failed to start shard
org.elasticsearch.index.gateway.IndexShardGatewayRecoveryException:
[6136561_xs][0] failed to recover shard
at
org.elasticsearch.index.gateway.local.LocalIndexShardGateway.recover(LocalIndexShardGateway.java:204)
at
org.elasticsearch.index.gateway.IndexShardGatewayService$1.run(IndexShardGatewayService.java:177)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.StringIndexOutOfBoundsException: String index out of
range: 0
at java.lang.String.charAt(Unknown Source)
at
org.elasticsearch.index.mapper.MapperService.add(MapperService.java:180)
at
org.elasticsearch.index.mapper.MapperService.add(MapperService.java:172)
at
org.elasticsearch.index.mapper.MapperService.documentMapperWithAutoCreate(MapperService.java:298)
at
org.elasticsearch.index.shard.service.InternalIndexShard.prepareIndex(InternalIndexShard.java:310)
at
org.elasticsearch.index.shard.service.InternalIndexShard.performRecoveryOperation(InternalIndexShard.java:624)
at
org.elasticsearch.index.gateway.local.LocalIndexShardGateway.recover(LocalIndexShardGateway.java:199)
... 4 more
[2012-05-11 05:07:59,065][WARN ][cluster.action.shard ] [es1-04]
sending failed shard for [6136561_xs][0], node[JYRwNCxDSESuFFQ5jvvSEg],
[P], s[INITIALIZING], reason [Failed to start shard, message
[IndexShardGatewayRecoveryException[[6136561_xs][0] failed to recover
shard]; nested: StringIndexOutOfBoundsException[String index out of range:
0]; ]]

Master was shut down but no other master was re-elected:
[2012-05-11 05:07:59,143][INFO ][discovery.zen ] [es1-04]
master_left
[[es1-01][LTA8l-oURImdrLeGo4HNDQ][inet[/10.1.101.151:9300]]{data_center=ny4}],
reason [failed to ping, tried [5] times, each with maximum [5s] timeout]
[2012-05-11 05:08:01,513][INFO ][discovery.zen ] [es1-04]
master_left
[[es1-01][LTA8l-oURImdrLeGo4HNDQ][inet[/10.1.101.151:9300]]{data_center=ny4}],
reason [failed to ping, tried [5] times, each with maximum [5s] timeout]

Claiming the shard doesn't exist locally but I've verified that it does (at
least such a directory exists and it has what seems like legitimate
content):

[2012-05-11 05:07:31,359][WARN ][indices.cluster ] [es1-02]
[6090102_m][0] failed to start shard
org.elasticsearch.index.gateway.IndexShardGatewayRecoveryException:
[6090102_m][0] shard allocated for local recovery (post api), should
exists, but doesn't
at
org.elasticsearch.index.gateway.local.LocalIndexShardGateway.recover(LocalIndexShardGateway.java:108)
at
org.elasticsearch.index.gateway.IndexShardGatewayService$1.run(IndexShardGatewayService.java:177)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)

Can't get cluster status:

[2012-05-11 05:08:14,426][DEBUG][action.admin.cluster.node.stats] [es1-05]
failed to execute on node [1zK5Dj6wT6OqNtwDJpJP8Q]
org.elasticsearch.transport.SendRequestTransportException:
[es1-02][inet[/10.1.101.152:9300]][cluster/nodes/stats/n]
at
org.elasticsearch.transport.TransportService.sendRequest(TransportService.java:200)
at
org.elasticsearch.action.support.nodes.TransportNodesOperationAction$AsyncAction.start(TransportNodesOperationAction.java:172)
at
org.elasticsearch.action.support.nodes.TransportNodesOperationAction$AsyncAction.access$300(TransportNodesOperationAction.java:102)
at
org.elasticsearch.action.support.nodes.TransportNodesOperationAction.doExecute(TransportNodesOperationAction.java:73)
at
org.elasticsearch.action.support.nodes.TransportNodesOperationAction.doExecute(TransportNodesOperationAction.java:43)
at
org.elasticsearch.action.support.TransportAction.execute(TransportAction.java:61)
at
org.elasticsearch.client.node.NodeClusterAdminClient.execute(NodeClusterAdminClient.java:70)
at
org.elasticsearch.client.support.AbstractClusterAdminClient.nodesStats(AbstractClusterAdminClient.java:150)
at
org.elasticsearch.rest.action.admin.cluster.node.stats.RestNodesStatsAction.executeNodeStats(RestNodesStatsAction.java:130)
at
org.elasticsearch.rest.action.admin.cluster.node.stats.RestNodesStatsAction.handleRequest(RestNodesStatsAction.java:125)
at
org.elasticsearch.rest.RestController.executeHandler(RestController.java:159)
at
org.elasticsearch.rest.RestController.dispatchRequest(RestController.java:142)
at
org.elasticsearch.http.HttpServer.internalDispatchRequest(HttpServer.java:120)
at
org.elasticsearch.http.HttpServer$Dispatcher.dispatchRequest(HttpServer.java:82)
at
org.elasticsearch.http.netty.NettyHttpServerTransport.dispatchRequest(NettyHttpServerTransport.java:259)
at
org.elasticsearch.http.netty.HttpRequestHandler.messageReceived(HttpRequestHandler.java:43)
at
org.elasticsearch.common.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:75)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:792)
at
org.elasticsearch.common.netty.handler.codec.http.HttpChunkAggregator.messageReceived(HttpChunkAggregator.java:111)
at
org.elasticsearch.common.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:75)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:792)
at
org.elasticsearch.common.netty.channel.Channels.fireMessageReceived(Channels.java:296)
at
org.elasticsearch.common.netty.handler.codec.replay.ReplayingDecoder.unfoldAndFireMessageReceived(ReplayingDecoder.java:567)
at
org.elasticsearch.common.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:551)
at
org.elasticsearch.common.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:445)
at
org.elasticsearch.common.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:75)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:792)
at
org.elasticsearch.common.netty.OpenChannelsHandler.handleUpstream(OpenChannelsHandler.java:74)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559)
at
org.elasticsearch.common.netty.channel.Channels.fireMessageReceived(Channels.java:268)
at
org.elasticsearch.common.netty.channel.Channels.fireMessageReceived(Channels.java:255)
at
org.elasticsearch.common.netty.channel.socket.nio.NioWorker.read(NioWorker.java:94)
at
org.elasticsearch.common.netty.channel.socket.nio.AbstractNioWorker.processSelectedKeys(AbstractNioWorker.java:364)
at
org.elasticsearch.common.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:238)
at
org.elasticsearch.common.netty.channel.socket.nio.NioWorker.run(NioWorker.java:38)
at
org.elasticsearch.common.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)
Caused by: org.elasticsearch.transport.NodeNotConnectedException:
[es1-02][inet[/10.1.101.152:9300]] Node not connected
at
org.elasticsearch.transport.netty.NettyTransport.nodeChannel(NettyTransport.java:637)
at
org.elasticsearch.transport.netty.NettyTransport.sendRequest(NettyTransport.java:445)
at
org.elasticsearch.transport.TransportService.sendRequest(TransportService.java:185)
... 42 more

Another flavor of the sending shard failed problem (here without the
exception details):
[2012-05-11 05:07:31,471][WARN ][cluster.action.shard ] [es1-02]
sending failed shard for [6090092_m][3], node[1zK5Dj6wT6OqNtwDJpJP8Q], [P],
s[INITIALIZING], reason [Failed to start shard, message
[IndexShardGatewayRecoveryException[[6090092_m][3] failed to recover
shard]; nested: StringIndexOutOfBoundsException[String index out of range:
0]; ]]
[2012-05-11 05:07:31,472][WARN ][cluster.action.shard ] [es1-02]
sending failed shard for [6134711_xs][0], node[1zK5Dj6wT6OqNtwDJpJP8Q],
[P], s[INITIALIZING], reason [Failed to start shard, message
[IndexShardGatewayRecoveryException[[6134711_xs][0] failed to recover
shard]; nested: StringIndexOutOfBoundsException[String index out of range:
0]; ]]

-eran

2

At least for the exceptions you posted, the reason for them is that you
upgraded to 0.19 without following the upgrade notes in the download page
(send a flush to all indices).

Regarding the others, if you can recreate them and check if they happen
with 0.19, it would be great.

On Sun, May 13, 2012 at 5:23 PM, Eran Kutner eran@gigya-inc.com wrote:

Hi,
I've encountered multiple issues after configuring shard allocation
awareness and doing a full cluster restart. From previous experience I can
say I've already seen such issues so I'm not sure if it's related to the
configuration change or the restart. It's going to be a long post so please
bare with me.

I started out with 5 servers running 0.18.5 and tried to add one
additional server using a different zone. The servers are not very busy or
loaded so one server can hold the data of the other 5. The 5 servers are
connected over fast LAN and were using multicast discovery and the new
server was connected over WAN and using unicast. I've also configured
forced awareness to make sure the data got replicated the way I wanted it
to. Then restarted the cluster servers one by one for the configuration
changes to take effect. After the restart a lot of shards remained
unallocated, even after a long time, so I've tried various things but here
is a summary of the issues:

  • Shards which are available on disk do not get loaded with message
    saying they are not there.
  • Some of the original servers didn't know the new server and said it
    wasn't a part of the cluster, this problem was mostly resolved after
    switching to full unicast configuration).
  • When the master node was taken down the other servers didn't elect a
    new master even after a very long wait. They just kept saying it was
    unreachable.
  • When the master was brought up again some servers would not connect
    to it anymore.
  • When trying to recover (using the local gateway) servers would try
    to connect to other servers and fail, usually with errors of connection
    interruption.
  • Although I have configured expected_nodes and recover_after_nodes
    the cluster would still wait the recover_after_time before starting the
    recovery even when all (or at least most) the nodes were up.

I've tried to get this to work for hours but the cluster state remained
red with many unloaded shards, eventually I gave up, wiped the entire
cluster and reindexed the data. The next day I tried adding another remote
server, in the same zone as the one added the day before and had exactly
the same problems. This time I also tried upgrading to 0.19.3 but that
didn't really improve anything, in fact it exposed some new exceptions that
were not present before. Again, after trying quite a lot to get it to work
I gave up wiped out the entire cluster and re-indexed the data.

Unfortunately I don't have the logs to support all of the above issues
because there seems to be a problem with the log rolling. It doesn't create
a new daily file but just overwrites the existing file, so all I have is
what I could scrape from open console sessions. The following exceptions
are not in any particular order, they are just random things I picked up
from my consoles but all of them happened many many times:

Index out of range exception:

[2012-05-11 05:07:58,092][WARN ][cluster.action.shard ] [es1-04]
sending failed shard for [6136561_xs][0], node[JYRwNCxDSESuFFQ5jvvSEg],
[P], s[INITIALIZING], reason [Failed to start shard, message
[IndexShardGatewayRecoveryException[[6136561_xs][0] failed to recover
shard]; nested: StringIndexOutOfBoundsException[String index out of range:
0]; ]]
[2012-05-11 05:07:58,602][WARN ][indices.cluster ] [es1-04]
[6136561_xs][0] failed to start shard
org.elasticsearch.index.gateway.IndexShardGatewayRecoveryException:
[6136561_xs][0] failed to recover shard
at
org.elasticsearch.index.gateway.local.LocalIndexShardGateway.recover(LocalIndexShardGateway.java:204)
at
org.elasticsearch.index.gateway.IndexShardGatewayService$1.run(IndexShardGatewayService.java:177)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.StringIndexOutOfBoundsException: String index out of
range: 0
at java.lang.String.charAt(Unknown Source)
at
org.elasticsearch.index.mapper.MapperService.add(MapperService.java:180)
at
org.elasticsearch.index.mapper.MapperService.add(MapperService.java:172)
at
org.elasticsearch.index.mapper.MapperService.documentMapperWithAutoCreate(MapperService.java:298)
at
org.elasticsearch.index.shard.service.InternalIndexShard.prepareIndex(InternalIndexShard.java:310)
at
org.elasticsearch.index.shard.service.InternalIndexShard.performRecoveryOperation(InternalIndexShard.java:624)
at
org.elasticsearch.index.gateway.local.LocalIndexShardGateway.recover(LocalIndexShardGateway.java:199)
... 4 more
[2012-05-11 05:07:59,065][WARN ][cluster.action.shard ] [es1-04]
sending failed shard for [6136561_xs][0], node[JYRwNCxDSESuFFQ5jvvSEg],
[P], s[INITIALIZING], reason [Failed to start shard, message
[IndexShardGatewayRecoveryException[[6136561_xs][0] failed to recover
shard]; nested: StringIndexOutOfBoundsException[String index out of range:
0]; ]]

Master was shut down but no other master was re-elected:
[2012-05-11 05:07:59,143][INFO ][discovery.zen ] [es1-04]
master_left [[es1-01][LTA8l-oURImdrLeGo4HNDQ][inet[/10.1.101.151:9300]]{data_center=ny4}],
reason [failed to ping, tried [5] times, each with maximum [5s] timeout]
[2012-05-11 05:08:01,513][INFO ][discovery.zen ] [es1-04]
master_left [[es1-01][LTA8l-oURImdrLeGo4HNDQ][inet[/10.1.101.151:9300]]{data_center=ny4}],
reason [failed to ping, tried [5] times, each with maximum [5s] timeout]

Claiming the shard doesn't exist locally but I've verified that it does
(at least such a directory exists and it has what seems like legitimate
content):

[2012-05-11 05:07:31,359][WARN ][indices.cluster ] [es1-02]
[6090102_m][0] failed to start shard
org.elasticsearch.index.gateway.IndexShardGatewayRecoveryException:
[6090102_m][0] shard allocated for local recovery (post api), should
exists, but doesn't
at
org.elasticsearch.index.gateway.local.LocalIndexShardGateway.recover(LocalIndexShardGateway.java:108)
at
org.elasticsearch.index.gateway.IndexShardGatewayService$1.run(IndexShardGatewayService.java:177)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)

Can't get cluster status:

[2012-05-11 05:08:14,426][DEBUG][action.admin.cluster.node.stats] [es1-05]
failed to execute on node [1zK5Dj6wT6OqNtwDJpJP8Q]
org.elasticsearch.transport.SendRequestTransportException:
[es1-02][inet[/10.1.101.152:9300]][cluster/nodes/stats/n]
at
org.elasticsearch.transport.TransportService.sendRequest(TransportService.java:200)
at
org.elasticsearch.action.support.nodes.TransportNodesOperationAction$AsyncAction.start(TransportNodesOperationAction.java:172)
at
org.elasticsearch.action.support.nodes.TransportNodesOperationAction$AsyncAction.access$300(TransportNodesOperationAction.java:102)
at
org.elasticsearch.action.support.nodes.TransportNodesOperationAction.doExecute(TransportNodesOperationAction.java:73)
at
org.elasticsearch.action.support.nodes.TransportNodesOperationAction.doExecute(TransportNodesOperationAction.java:43)
at
org.elasticsearch.action.support.TransportAction.execute(TransportAction.java:61)
at
org.elasticsearch.client.node.NodeClusterAdminClient.execute(NodeClusterAdminClient.java:70)
at
org.elasticsearch.client.support.AbstractClusterAdminClient.nodesStats(AbstractClusterAdminClient.java:150)
at
org.elasticsearch.rest.action.admin.cluster.node.stats.RestNodesStatsAction.executeNodeStats(RestNodesStatsAction.java:130)
at
org.elasticsearch.rest.action.admin.cluster.node.stats.RestNodesStatsAction.handleRequest(RestNodesStatsAction.java:125)
at
org.elasticsearch.rest.RestController.executeHandler(RestController.java:159)
at
org.elasticsearch.rest.RestController.dispatchRequest(RestController.java:142)
at
org.elasticsearch.http.HttpServer.internalDispatchRequest(HttpServer.java:120)
at
org.elasticsearch.http.HttpServer$Dispatcher.dispatchRequest(HttpServer.java:82)
at
org.elasticsearch.http.netty.NettyHttpServerTransport.dispatchRequest(NettyHttpServerTransport.java:259)
at
org.elasticsearch.http.netty.HttpRequestHandler.messageReceived(HttpRequestHandler.java:43)
at
org.elasticsearch.common.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:75)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:792)
at
org.elasticsearch.common.netty.handler.codec.http.HttpChunkAggregator.messageReceived(HttpChunkAggregator.java:111)
at
org.elasticsearch.common.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:75)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:792)
at
org.elasticsearch.common.netty.channel.Channels.fireMessageReceived(Channels.java:296)
at
org.elasticsearch.common.netty.handler.codec.replay.ReplayingDecoder.unfoldAndFireMessageReceived(ReplayingDecoder.java:567)
at
org.elasticsearch.common.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:551)
at
org.elasticsearch.common.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:445)
at
org.elasticsearch.common.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:75)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:792)
at
org.elasticsearch.common.netty.OpenChannelsHandler.handleUpstream(OpenChannelsHandler.java:74)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
at
org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559)
at
org.elasticsearch.common.netty.channel.Channels.fireMessageReceived(Channels.java:268)
at
org.elasticsearch.common.netty.channel.Channels.fireMessageReceived(Channels.java:255)
at
org.elasticsearch.common.netty.channel.socket.nio.NioWorker.read(NioWorker.java:94)
at
org.elasticsearch.common.netty.channel.socket.nio.AbstractNioWorker.processSelectedKeys(AbstractNioWorker.java:364)
at
org.elasticsearch.common.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:238)
at
org.elasticsearch.common.netty.channel.socket.nio.NioWorker.run(NioWorker.java:38)
at
org.elasticsearch.common.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)
Caused by: org.elasticsearch.transport.NodeNotConnectedException:
[es1-02][inet[/10.1.101.152:9300]] Node not connected
at
org.elasticsearch.transport.netty.NettyTransport.nodeChannel(NettyTransport.java:637)
at
org.elasticsearch.transport.netty.NettyTransport.sendRequest(NettyTransport.java:445)
at
org.elasticsearch.transport.TransportService.sendRequest(TransportService.java:185)
... 42 more

Another flavor of the sending shard failed problem (here without the
exception details):
[2012-05-11 05:07:31,471][WARN ][cluster.action.shard ] [es1-02]
sending failed shard for [6090092_m][3], node[1zK5Dj6wT6OqNtwDJpJP8Q], [P],
s[INITIALIZING], reason [Failed to start shard, message
[IndexShardGatewayRecoveryException[[6090092_m][3] failed to recover
shard]; nested: StringIndexOutOfBoundsException[String index out of range:
0]; ]]
[2012-05-11 05:07:31,472][WARN ][cluster.action.shard ] [es1-02]
sending failed shard for [6134711_xs][0], node[1zK5Dj6wT6OqNtwDJpJP8Q],
[P], s[INITIALIZING], reason [Failed to start shard, message
[IndexShardGatewayRecoveryException[[6134711_xs][0] failed to recover
shard]; nested: StringIndexOutOfBoundsException[String index out of range:
0]; ]]

-eran

3

I'm now trying to reproduce the same issues with 0.19.3
After restarting the first server it started writing these in the log:
[2012-05-20 08:03:52,142][DEBUG][action.admin.indices.status] [es1-01]
[6153091_m][0], node[gI5yXeQoShCAmD6iN7rXFw], [R], s[INITIALIZING]: Failed
to execute
[org.elasticsearch.action.admin.indices.status.IndicesStatusRequest@48129552]
org.elasticsearch.transport.RemoteTransportException:
[es1-03][inet[/10.1.101.153:9300]][indices/status/s]
Caused by: org.elasticsearch.index.IndexShardMissingException:
[6153091_m][0] missing
at
org.elasticsearch.index.service.InternalIndexService.shardSafe(InternalIndexService.java:175)
at
org.elasticsearch.action.admin.indices.status.TransportIndicesStatusAction.shardOperation(TransportIndicesStatusAction.java:153)
at
org.elasticsearch.action.admin.indices.status.TransportIndicesStatusAction.shardOperation(TransportIndicesStatusAction.java:59)
at
org.elasticsearch.action.support.broadcast.TransportBroadcastOperationAction$ShardTransportHandler.messageReceived(TransportBroadcastOperationAction.java:398)
at
org.elasticsearch.action.support.broadcast.TransportBroadcastOperationAction$ShardTransportHandler.messageReceived(TransportBroadcastOperationAction.java:384)
at
org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.run(MessageChannelHandler.java:374)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)
[2012-05-20 08:03:52,147][DEBUG][action.admin.indices.status] [es1-01]
[6099052_m][1], node[xlUDFXu8SguLn2K4gM0ehA], [R], s[INITIALIZING]: Failed
to execute
[org.elasticsearch.action.admin.indices.status.IndicesStatusRequest@48129552]
org.elasticsearch.transport.RemoteTransportException:
[es1-01][inet[/10.1.101.151:9300]][indices/status/s]
Caused by: org.elasticsearch.index.IndexShardMissingException:
[6099052_m][1] missing
at
org.elasticsearch.index.service.InternalIndexService.shardSafe(InternalIndexService.java:175)
at
org.elasticsearch.action.admin.indices.status.TransportIndicesStatusAction.shardOperation(TransportIndicesStatusAction.java:153)
at
org.elasticsearch.action.admin.indices.status.TransportIndicesStatusAction.shardOperation(TransportIndicesStatusAction.java:59)
at
org.elasticsearch.action.support.broadcast.TransportBroadcastOperationAction$ShardTransportHandler.messageReceived(TransportBroadcastOperationAction.java:398)
at
org.elasticsearch.action.support.broadcast.TransportBroadcastOperationAction$ShardTransportHandler.messageReceived(TransportBroadcastOperationAction.java:384)
at
org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.run(MessageChannelHandler.java:374)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)

After a while the cluster did turn green and all the shards were loaded, so
I went ahead and restarted another server, which also was OK, so I
restarted another server and also added 2 additional servers in the new
zone I'm trying to create.

I didn't get any special errors but the cluster got stuck in yellow state
with 26 shards in status "initializing", and nothing else was happening. I
checked which nodes had the "stuck" shards picked the one that had the most
and restarted it, that server didn't have any issues but after a while
other servers (the three that were previously restarted) started reporting
out of memory errors, that, on servers with 64GB or RAM, which never had
memory issues before.

So I restarted those servers but in their logs there is no indication they
have connected to a master, even after waiting for a very long time. Here
is an example log file taken 15 minutes after the restart:
[2012-05-20 10:45:49,698][INFO ][node ] [es1-05]
{0.19.3}[22622]: initializing ...
[2012-05-20 10:45:49,706][INFO ][plugins ] [es1-05] loaded
[], sites [head]
[2012-05-20 10:45:52,518][INFO ][node ] [es1-05]
{0.19.3}[22622]: initialized
[2012-05-20 10:45:52,518][INFO ][node ] [es1-05]
{0.19.3}[22622]: starting ...
[2012-05-20 10:45:52,574][INFO ][transport ] [es1-05]
bound_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish_address
{inet[/10.1.101.155:9300]}
[2012-05-20 10:46:22,583][WARN ][discovery ] [es1-05] waited
for 30s and no initial state was set by the discovery
[2012-05-20 10:46:22,583][INFO ][discovery ] [es1-05]
gcs/glRWDD8qSgmh-ohOAABs8g
[2012-05-20 10:46:22,591][INFO ][http ] [es1-05]
bound_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish_address
{inet[/10.1.101.155:9200]}
[2012-05-20 10:46:23,111][INFO ][jmx ] [es1-05]
bound_address {service:jmx:rmi:///jndi/rmi://:9400/jmxrmi}, publish_address
{service:jmx:rmi:///jndi/rmi://10.1.101.155:9400/jmxrmi}
[2012-05-20 10:46:23,112][INFO ][node ] [es1-05]
{0.19.3}[22622]: started

At this time the server es1-02 thinks its the master and two other servers
in the cluster agree. But the log on es1-02 shows that it keeps trying to
connect to the servers that were unable to connct to the cluster and fails.
For example:
[2012-05-20 11:04:45,033][DEBUG][action.admin.cluster.node.stats] [es1-02]
failed to execute on node [fwORyJ2wT8S-rsDDlkZFoA]
org.elasticsearch.transport.RemoteTransportException:
[es1-05][inet[/10.1.101.155:9300]][cluster/nodes/stats/n]
Caused by: java.lang.NullPointerException
at
org.elasticsearch.action.support.nodes.NodeOperationResponse.writeTo(NodeOperationResponse.java:66)
at
org.elasticsearch.action.admin.cluster.node.stats.NodeStats.writeTo(NodeStats.java:290)
at
org.elasticsearch.transport.support.TransportStreams.buildResponse(TransportStreams.java:131)
at
org.elasticsearch.transport.netty.NettyTransportChannel.sendResponse(NettyTransportChannel.java:77)
at
org.elasticsearch.transport.netty.NettyTransportChannel.sendResponse(NettyTransportChannel.java:68)
at
org.elasticsearch.action.support.nodes.TransportNodesOperationAction$NodeTransportHandler.messageReceived(TransportNodesOperationAction.java:276)
at
org.elasticsearch.action.support.nodes.TransportNodesOperationAction$NodeTransportHandler.messageReceived(TransportNodesOperationAction.java:267)
at
org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.run(MessageChannelHandler.java:374)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)

Now the only thing I could think of was restarting es1-02 to force the
election of a new master. Now the same servers that didn't indicate they
connected to a master before reported in their logs:
[2012-05-20 11:05:57,530][INFO ][discovery.zen ] [es1-05]
master_left
[[es1-02][k7EYRZmKQLW99x82DB5usA][inet[/10.1.101.152:9300]]{data_center=ny4}],
reason [shut_down]
[2012-05-20 11:05:57,562][INFO ][discovery.zen ] [es1-05]
master_left
[[es1-02][k7EYRZmKQLW99x82DB5usA][inet[/10.1.101.152:9300]]{data_center=ny4}],
reason [transport disconnected (with verified connect)]
[2012-05-20 11:05:59,738][WARN ][discovery.zen ] [es1-05]
received a cluster state from
[[es1-aws-02][F6w1rtXSRcCHd3rxSloT-Q][inet[/10.2.101.18:9300]]{data_center=ny4}]
and not part of the cluster, should not happen
[2012-05-20 11:06:01,545][WARN ][discovery.zen ] [es1-05]
received a cluster state from
[[es1-aws-02][F6w1rtXSRcCHd3rxSloT-Q][inet[/10.2.101.18:9300]]{data_center=ny4}]
and not part of the cluster, should not happen
[2012-05-20 11:06:04,610][WARN ][discovery.zen ] [es1-05]
received a cluster state from
[[es1-aws-02][F6w1rtXSRcCHd3rxSloT-Q][inet[/10.2.101.18:9300]]{data_center=ny4}]
and not part of the cluster, should not happen

I should note that es1-aws-02 is configured as a unicast host on all the
other servers.
Now the cluster is red, showing only 3 connected servers out of the
expected 7 and stuck with 4 initializaing shards and 1036 unassigned
shards. Restating the "stuck" servers again, now they do detect the master:
[2012-05-20 11:11:38,385][INFO ][node ] [es1-05]
{0.19.3}[23642]: initializing ...
[2012-05-20 11:11:38,393][INFO ][plugins ] [es1-05] loaded
[], sites [head]
[2012-05-20 11:11:41,351][INFO ][node ] [es1-05]
{0.19.3}[23642]: initialized
[2012-05-20 11:11:41,351][INFO ][node ] [es1-05]
{0.19.3}[23642]: starting ...
[2012-05-20 11:11:41,442][INFO ][transport ] [es1-05]
bound_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish_address
{inet[/10.1.101.155:9300]}
[2012-05-20 11:11:44,705][INFO ][cluster.service ] [es1-05]
detected_master
[es1-aws-02][F6w1rtXSRcCHd3rxSloT-Q][inet[/10.2.101.18:9300]]{data_center=ny4},
added
{[es1-aws-01][_HzOEQgoS36DpFZY6_wy1g][inet[/10.2.101.17:9300]]{data_center=ny4},[es1-aws-02][F6w1rtXSRcCHd3rxSloT-Q][inet[/10.2.101.18:9300]]{data_center=ny4},[es1-02][OfThjq3gRU699-v2bJJA2w][inet[/10.1.101.152:9300]]{data_center=ny4},},
reason: zen-disco-receive(from master
[[es1-aws-02][F6w1rtXSRcCHd3rxSloT-Q][inet[/10.2.101.18:9300]]{data_center=ny4}])
[2012-05-20 11:11:45,736][INFO ][discovery ] [es1-05]
gcs/RLX9x3poQKyMiTjQb57_oQ
[2012-05-20 11:11:45,747][INFO ][http ] [es1-05]
bound_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish_address
{inet[/10.1.101.155:9200]}
[2012-05-20 11:11:46,269][INFO ][jmx ] [es1-05]
bound_address {service:jmx:rmi:///jndi/rmi://:9400/jmxrmi}, publish_address
{service:jmx:rmi:///jndi/rmi://10.1.101.155:9400/jmxrmi}
[2012-05-20 11:11:46,269][INFO ][node ] [es1-05]
{0.19.3}[23642]: started

Now, finally all servers are on the cluster again, and the status is yellow
again but with 0 initializing shards, 0 relocating shards and 147
unassigned shards. It is now stuck like that and the logs don't show
anytihng intersting.

Any suggestions what to do now?

Thanks,
Eran

4

I've now tried restarting the current master which was es1-aws-02
some servers seem to have elected a new master es1-05:
[2012-05-20 12:34:11,452][INFO ][cluster.service ] [es1-04] master
{new
[es1-05][RLX9x3poQKyMiTjQb57_oQ][inet[/10.1.101.155:9300]]{data_center=ny4},
previous
[es1-02][OfThjq3gRU699-v2bJJA2w][inet[/10.1.101.152:9300]]{data_center=ny4}},
removed
{[es1-02][OfThjq3gRU699-v2bJJA2w][inet[/10.1.101.152:9300]]{data_center=ny4},},
reason: zen-disco-receive(from master
[[es1-05][RLX9x3poQKyMiTjQb57_oQ][inet[/10.1.101.155:9300]]{data_center=ny4}])

Others elected es1-01 as master:
[2012-05-20 16:39:02,037][INFO ][cluster.service ] [es1-aws-02]
detected_master
[es1-01][1YFp6GmJQHqIzHVBGjyNsQ][inet[/10.1.101.151:9300]]{data_center=ny4},
added
{[es1-03][U3l_H6c4ThmpgCfQSmZseQ][inet[/10.1.101.153:9300]]{data_center=ny4},[es1-aws-01][4eyopgERR-6i0CNQPhA-uQ][inet[/10.2.101.17:9300]]{data_center=us-east-1},[es1-05][RLX9x3poQKyMiTjQb57_oQ][inet[/10.1.101.155:9300]]{data_center=ny4},[es1-02][OfThjq3gRU699-v2bJJA2w][inet[/10.1.101.152:9300]]{data_center=ny4},[es1-04][ub7Ak7ckQ_imuk-v0uFQ8g][inet[/10.1.101.154:9300]]{data_center=ny4},[es1-01][1YFp6GmJQHqIzHVBGjyNsQ][inet[/10.1.101.151:9300]]{data_center=ny4},},
reason: zen-disco-receive(from master
[[es1-01][1YFp6GmJQHqIzHVBGjyNsQ][inet[/10.1.101.151:9300]]{data_center=ny4}])

While others decided to elect themselves as masters
[2012-05-20 16:38:38,818][WARN ][discovery.zen ] [es1-aws-01]
master should not receive new cluster state from
[[es1-01][1YFp6GmJQHqIzHVBGjyNsQ][inet[/10.1.101.151:9300]]{data_center=ny4}]
[2012-05-20 12:38:56,440][WARN ][discovery.zen ] [es1-02] master
should not receive new cluster state from
[[es1-01][1YFp6GmJQHqIzHVBGjyNsQ][inet[/10.1.101.151:9300]]{data_center=ny4}]

5

Lets start from the beginning, to simplify this. First, the index status
API failures you can ignore.

Lets focus first on the first part where shards were "stuck" initializing.

I don't really understand which servers you start on which zone. I assume
you use shard allocation rules, possibly forced? In this case which servers
and with what configuration did you start them with? Are you running the
cluster across multiple remote data centers? Its not recommended unless the
connection between them is reliable and fast.

On Sun, May 20, 2012 at 5:26 PM, Eran Kutner eran@gigya-inc.com wrote:

I'm now trying to reproduce the same issues with 0.19.3
After restarting the first server it started writing these in the log:
[2012-05-20 08:03:52,142][DEBUG][action.admin.indices.status] [es1-01]
[6153091_m][0], node[gI5yXeQoShCAmD6iN7rXFw], [R], s[INITIALIZING]: Failed
to execute
[org.elasticsearch.action.admin.indices.status.IndicesStatusRequest@48129552
]
org.elasticsearch.transport.RemoteTransportException:
[es1-03][inet[/10.1.101.153:9300]][indices/status/s]
Caused by: org.elasticsearch.index.IndexShardMissingException:
[6153091_m][0] missing
at
org.elasticsearch.index.service.InternalIndexService.shardSafe(InternalIndexService.java:175)
at
org.elasticsearch.action.admin.indices.status.TransportIndicesStatusAction.shardOperation(TransportIndicesStatusAction.java:153)
at
org.elasticsearch.action.admin.indices.status.TransportIndicesStatusAction.shardOperation(TransportIndicesStatusAction.java:59)
at
org.elasticsearch.action.support.broadcast.TransportBroadcastOperationAction$ShardTransportHandler.messageReceived(TransportBroadcastOperationAction.java:398)
at
org.elasticsearch.action.support.broadcast.TransportBroadcastOperationAction$ShardTransportHandler.messageReceived(TransportBroadcastOperationAction.java:384)
at
org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.run(MessageChannelHandler.java:374)

    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown

Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)
[2012-05-20 08:03:52,147][DEBUG][action.admin.indices.status] [es1-01]
[6099052_m][1], node[xlUDFXu8SguLn2K4gM0ehA], [R], s[INITIALIZING]: Failed
to execute
[org.elasticsearch.action.admin.indices.status.IndicesStatusRequest@48129552
]
org.elasticsearch.transport.RemoteTransportException:
[es1-01][inet[/10.1.101.151:9300]][indices/status/s]
Caused by: org.elasticsearch.index.IndexShardMissingException:
[6099052_m][1] missing
at
org.elasticsearch.index.service.InternalIndexService.shardSafe(InternalIndexService.java:175)
at
org.elasticsearch.action.admin.indices.status.TransportIndicesStatusAction.shardOperation(TransportIndicesStatusAction.java:153)
at
org.elasticsearch.action.admin.indices.status.TransportIndicesStatusAction.shardOperation(TransportIndicesStatusAction.java:59)
at
org.elasticsearch.action.support.broadcast.TransportBroadcastOperationAction$ShardTransportHandler.messageReceived(TransportBroadcastOperationAction.java:398)
at
org.elasticsearch.action.support.broadcast.TransportBroadcastOperationAction$ShardTransportHandler.messageReceived(TransportBroadcastOperationAction.java:384)
at
org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.run(MessageChannelHandler.java:374)

    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown

Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)

After a while the cluster did turn green and all the shards were loaded,
so I went ahead and restarted another server, which also was OK, so I
restarted another server and also added 2 additional servers in the new
zone I'm trying to create.

I didn't get any special errors but the cluster got stuck in yellow state
with 26 shards in status "initializing", and nothing else was happening. I
checked which nodes had the "stuck" shards picked the one that had the most
and restarted it, that server didn't have any issues but after a while
other servers (the three that were previously restarted) started reporting
out of memory errors, that, on servers with 64GB or RAM, which never had
memory issues before.

So I restarted those servers but in their logs there is no indication they
have connected to a master, even after waiting for a very long time. Here
is an example log file taken 15 minutes after the restart:
[2012-05-20 10:45:49,698][INFO ][node ] [es1-05]
{0.19.3}[22622]: initializing ...
[2012-05-20 10:45:49,706][INFO ][plugins ] [es1-05]
loaded , sites [head]
[2012-05-20 10:45:52,518][INFO ][node ] [es1-05]
{0.19.3}[22622]: initialized
[2012-05-20 10:45:52,518][INFO ][node ] [es1-05]
{0.19.3}[22622]: starting ...
[2012-05-20 10:45:52,574][INFO ][transport ] [es1-05]
bound_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish_address {inet[/
10.1.101.155:9300]}
[2012-05-20 10:46:22,583][WARN ][discovery ] [es1-05]
waited for 30s and no initial state was set by the discovery
[2012-05-20 10:46:22,583][INFO ][discovery ] [es1-05]
gcs/glRWDD8qSgmh-ohOAABs8g
[2012-05-20 10:46:22,591][INFO ][http ] [es1-05]
bound_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish_address {inet[/
10.1.101.155:9200]}
[2012-05-20 10:46:23,111][INFO ][jmx ] [es1-05]
bound_address {service:jmx:rmi:///jndi/rmi://:9400/jmxrmi}, publish_address
{service:jmx:rmi:///jndi/rmi://10.1.101.155:9400/jmxrmi}
[2012-05-20 10:46:23,112][INFO ][node ] [es1-05]
{0.19.3}[22622]: started

At this time the server es1-02 thinks its the master and two other servers
in the cluster agree. But the log on es1-02 shows that it keeps trying to
connect to the servers that were unable to connct to the cluster and fails.
For example:
[2012-05-20 11:04:45,033][DEBUG][action.admin.cluster.node.stats] [es1-02]
failed to execute on node [fwORyJ2wT8S-rsDDlkZFoA]
org.elasticsearch.transport.RemoteTransportException:
[es1-05][inet[/10.1.101.155:9300]][cluster/nodes/stats/n]
Caused by: java.lang.NullPointerException
at
org.elasticsearch.action.support.nodes.NodeOperationResponse.writeTo(NodeOperationResponse.java:66)
at
org.elasticsearch.action.admin.cluster.node.stats.NodeStats.writeTo(NodeStats.java:290)
at
org.elasticsearch.transport.support.TransportStreams.buildResponse(TransportStreams.java:131)
at
org.elasticsearch.transport.netty.NettyTransportChannel.sendResponse(NettyTransportChannel.java:77)
at
org.elasticsearch.transport.netty.NettyTransportChannel.sendResponse(NettyTransportChannel.java:68)
at
org.elasticsearch.action.support.nodes.TransportNodesOperationAction$NodeTransportHandler.messageReceived(TransportNodesOperationAction.java:276)
at
org.elasticsearch.action.support.nodes.TransportNodesOperationAction$NodeTransportHandler.messageReceived(TransportNodesOperationAction.java:267)
at
org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.run(MessageChannelHandler.java:374)

    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown

Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)

Now the only thing I could think of was restarting es1-02 to force the
election of a new master. Now the same servers that didn't indicate they
connected to a master before reported in their logs:
[2012-05-20 11:05:57,530][INFO ][discovery.zen ] [es1-05]
master_left [[es1-02][k7EYRZmKQLW99x82DB5usA][inet[/10.1.101.152:9300]]{data_center=ny4}],
reason [shut_down]
[2012-05-20 11:05:57,562][INFO ][discovery.zen ] [es1-05]
master_left [[es1-02][k7EYRZmKQLW99x82DB5usA][inet[/10.1.101.152:9300]]{data_center=ny4}],
reason [transport disconnected (with verified connect)]
[2012-05-20 11:05:59,738][WARN ][discovery.zen ] [es1-05]
received a cluster state from
[[es1-aws-02][F6w1rtXSRcCHd3rxSloT-Q][inet[/10.2.101.18:9300]]{data_center=ny4}]
and not part of the cluster, should not happen
[2012-05-20 11:06:01,545][WARN ][discovery.zen ] [es1-05]
received a cluster state from
[[es1-aws-02][F6w1rtXSRcCHd3rxSloT-Q][inet[/10.2.101.18:9300]]{data_center=ny4}]
and not part of the cluster, should not happen
[2012-05-20 11:06:04,610][WARN ][discovery.zen ] [es1-05]
received a cluster state from
[[es1-aws-02][F6w1rtXSRcCHd3rxSloT-Q][inet[/10.2.101.18:9300]]{data_center=ny4}]
and not part of the cluster, should not happen

I should note that es1-aws-02 is configured as a unicast host on all the
other servers.
Now the cluster is red, showing only 3 connected servers out of the
expected 7 and stuck with 4 initializaing shards and 1036 unassigned
shards. Restating the "stuck" servers again, now they do detect the master:
[2012-05-20 11:11:38,385][INFO ][node ] [es1-05]
{0.19.3}[23642]: initializing ...
[2012-05-20 11:11:38,393][INFO ][plugins ] [es1-05]
loaded , sites [head]
[2012-05-20 11:11:41,351][INFO ][node ] [es1-05]
{0.19.3}[23642]: initialized
[2012-05-20 11:11:41,351][INFO ][node ] [es1-05]
{0.19.3}[23642]: starting ...
[2012-05-20 11:11:41,442][INFO ][transport ] [es1-05]
bound_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish_address {inet[/
10.1.101.155:9300]}
[2012-05-20 11:11:44,705][INFO ][cluster.service ] [es1-05]
detected_master [es1-aws-02][F6w1rtXSRcCHd3rxSloT-Q][inet[/10.2.101.18:9300]]{data_center=ny4},
added {[es1-aws-01][_HzOEQgoS36DpFZY6_wy1g][inet[/10.2.101.17:9300
]]{data_center=ny4},[es1-aws-02][F6w1rtXSRcCHd3rxSloT-Q][inet[/10.2.101.18:9300
]]{data_center=ny4},[es1-02][OfThjq3gRU699-v2bJJA2w][inet[/10.1.101.152:9300]]{data_center=ny4},},
reason: zen-disco-receive(from master
[[es1-aws-02][F6w1rtXSRcCHd3rxSloT-Q][inet[/10.2.101.18:9300
]]{data_center=ny4}])
[2012-05-20 11:11:45,736][INFO ][discovery ] [es1-05]
gcs/RLX9x3poQKyMiTjQb57_oQ
[2012-05-20 11:11:45,747][INFO ][http ] [es1-05]
bound_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish_address {inet[/
10.1.101.155:9200]}
[2012-05-20 11:11:46,269][INFO ][jmx ] [es1-05]
bound_address {service:jmx:rmi:///jndi/rmi://:9400/jmxrmi}, publish_address
{service:jmx:rmi:///jndi/rmi://10.1.101.155:9400/jmxrmi}
[2012-05-20 11:11:46,269][INFO ][node ] [es1-05]
{0.19.3}[23642]: started

Now, finally all servers are on the cluster again, and the status is
yellow again but with 0 initializing shards, 0 relocating shards and 147
unassigned shards. It is now stuck like that and the logs don't show
anytihng intersting.

Any suggestions what to do now?

Thanks,
Eran

6

I am trying to configure the system to run across two data centers and the
connection between is reliable and fast enough.

My configuration is 5 servers in one data center (DC1), they are called
es1-0x (where x=1->5) and two servers in another data center (DC2) called
es1-aws-0y (where y=1->2)
Discovery is using multicast within DC1 and unicast with in DC2 and between
the data centers. So on the servers within DC1 only the two servers of DC2
are configured in the unicast hosts list, while within DC2 the IP addresses
of all 7 servers of the cluster are included in the unicast hosts list.

I am using forced awareness where the two possible data centers names are
defined on all the servers in the cluster.

After analyzing all the events I think they can be summarized in 3 issues:

  • Master election issues - sometimes servers can't find the master when
    they are started and multiple servers elect themselves as masters.
  • Shards which are physically available on certain servers are reported
    as unavailable by those servers.
  • Shards get stuck in "initializing" and "unassigned" state until their
    servers are restarted.

I must say that have a strong feeling none of these issues are actually
related to allocation awareness.

By the way, after enough carefully selected restarts all the nodes in the
cluster agreed on the same master and everything started working, and still
does for the last 2 days without any problems. Unfortunately the elected
master is in DC2 where I'd rather it was in DC1 but I'd rather leave it
like that than risk another master selection issue if I take it down
(couldn't find a way to promote another server to be a master without
taking down the current master).

-eran

7

Heya,

  • Can you try and move to full unicast discovery with no multicast, lets
    see if it helps.
  • The number of nodes should be balanced between the two DCs, as shards
    will be allocated between then using forced awareness. Unless you use more
    than 1 replica, in which case, just make sure things are properly balanced.

On Tue, May 22, 2012 at 12:56 PM, Eran Kutner eran@gigya.com wrote:

I am trying to configure the system to run across two data centers and the
connection between is reliable and fast enough.

My configuration is 5 servers in one data center (DC1), they are called
es1-0x (where x=1->5) and two servers in another data center (DC2) called
es1-aws-0y (where y=1->2)
Discovery is using multicast within DC1 and unicast with in DC2 and
between the data centers. So on the servers within DC1 only the two servers
of DC2 are configured in the unicast hosts list, while within DC2 the IP
addresses of all 7 servers of the cluster are included in the unicast hosts
list.

I am using forced awareness where the two possible data centers names are
defined on all the servers in the cluster.

After analyzing all the events I think they can be summarized in 3 issues:

  • Master election issues - sometimes servers can't find the master
    when they are started and multiple servers elect themselves as masters.
  • Shards which are physically available on certain servers are
    reported as unavailable by those servers.
  • Shards get stuck in "initializing" and "unassigned" state until
    their servers are restarted.

I must say that have a strong feeling none of these issues are actually
related to allocation awareness.

By the way, after enough carefully selected restarts all the nodes in the
cluster agreed on the same master and everything started working, and still
does for the last 2 days without any problems. Unfortunately the elected
master is in DC2 where I'd rather it was in DC1 but I'd rather leave it
like that than risk another master selection issue if I take it down
(couldn't find a way to promote another server to be a master without
taking down the current master).

-eran

8

Tried that, it seemed to be a little better but still had the same kind of problems and the fact that it seemed better could be random as the entire issue seems random by nature.
The shards are more or less balanced. I have two replicas at the primary site and one at the secondary.

-eran