6.5.1 和 5.6.2 之间不稳定的跨集群搜索

Shaky Cross-Cluster Search between 6.5.1 and 5.6.2

这是我们的背景。我们有一个 ES 5.6.2 集群,有 23 个节点 (3M + 20D)。在我们迁移到 5.6.2 之前在该集群上创建了大约一半的索引,在迁移之后创建了另一半。为了受益于更新的功能并跟上新版本的步伐,我们决定:

  1. 通过将旧索引(在 ES 2 中创建)留在 5.6.2 集群上,将该集群一分为二
  2. 将较新的索引(在 5.6 中创建)移动到由 ES 6.5.1 提供支持的新集群
  3. 并在 6.5.1(新)-> 5.6.2(旧)之间单向设置 CCS

这种拆分背后的基本原理是,旧的索引非常庞大,可以在不中断业务的情况下重新索引到 ES 6.5.1 中。这将需要数周时间。不过,我们可能在某个时候仍然会这样做,但是由于这些索引在某个时候会是 frozen,所以我们没有看到浪费时间迁移将要 die/freeze 的数据的意义所在.

因此,我们对将较新的索引移至 6.5.1 非常有信心,而且确实进行得很顺利。分片分配过滤帮助我们移动节点上的所有索引,这些节点将成为新 6.5.1 集群的一部分。然后,在滚动迁移中,我们将这些节点中的每一个都迁移到新的 6.5.1 集群中,该集群从那时起就一直运行良好。

接下来是棘手的部分,您可能已经看到了。我们使用旧集群中的三个种子(数据)节点设置了 CCS,而这正是旧集群开始动摇的时候。除了我们发现并提交的 another CCS search bug 之外,症状是数据节点经常离开并重新加入集群,导致几乎持续的分片重新平衡。

换句话说,我们留下了一个黄色的集群,我们担心它随时可能变红。有时,它会再次变绿几分钟,然后变回黄色(有时会在很短的时间内变红)。请参阅下面的运行状况历史记录(左侧的大初始红色状态是我们将新索引移至新集群时,但所有其他 green/red 箭头对都是临时红色状态,因为我们将要处理的错误接下来描述):

具体来说,我们在旧 5.6.2 集群的主节点日志中看到的是,在发生以下一系列事件后,主节点将断开与数据节点的连接:

首先,我们看到以下错误(与 #23939 非常相似),其中我们看到节点无法获得给定分片上的锁。 (注意:我们广泛使用滚动搜索,所以这可能是那个问题中解释的原因)

[2019-02-14T23:53:38,331][WARN ][o.e.c.a.s.ShardStateAction] [IK-PRD-M3] [transactions_2016][1] received shard failed for shard id [[transactions_2016][1]], allocation id [Hy0REX6nScy49_2uXpKqrw], primary term [0], message [failed to create shard], failure [IOException[failed to obtain in-memory shard lock]; nested: ShardLockObtainFailedException[[transactions_2016][1]: obtaining shard lock timed out after 5000ms]; ]
java.io.IOException: failed to obtain in-memory shard lock
at org.elasticsearch.index.IndexService.createShard(IndexService.java:364) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.indices.IndicesService.createShard(IndicesService.java:499) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.indices.IndicesService.createShard(IndicesService.java:147) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.indices.cluster.IndicesClusterStateService.createShard(IndicesClusterStateService.java:542) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.indices.cluster.IndicesClusterStateService.createOrUpdateShards(IndicesClusterStateService.java:519) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.indices.cluster.IndicesClusterStateService.applyClusterState(IndicesClusterStateService.java:204) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.cluster.service.ClusterService.callClusterStateAppliers(ClusterService.java:814) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.cluster.service.ClusterService.publishAndApplyChanges(ClusterService.java:768) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.cluster.service.ClusterService.runTasks(ClusterService.java:587) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.cluster.service.ClusterService$ClusterServiceTaskBatcher.run(ClusterService.java:263) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.cluster.service.TaskBatcher.runIfNotProcessed(TaskBatcher.java:150) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.cluster.service.TaskBatcher$BatchedTask.run(TaskBatcher.java:188) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingRunnable.run(ThreadContext.java:569) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.runAndClean(PrioritizedEsThreadPoolExecutor.java:247) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.run(PrioritizedEsThreadPoolExecutor.java:210) ~[elasticsearch-5.6.2.jar:5.6.2]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[?:1.8.0_74]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[?:1.8.0_74]
at java.lang.Thread.run(Thread.java:745) [?:1.8.0_74]
Caused by: org.elasticsearch.env.ShardLockObtainFailedException: [transactions_2016][1]: obtaining shard lock timed out after 5000ms
at org.elasticsearch.env.NodeEnvironment$InternalShardLock.acquire(NodeEnvironment.java:724) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.env.NodeEnvironment.shardLock(NodeEnvironment.java:643) ~[elasticsearch-5.6.2.jar:5.6.2]
at org.elasticsearch.index.IndexService.createShard(IndexService.java:294) ~[elasticsearch-5.6.2.jar:5.6.2]
... 17 more

紧接着,我们发现了无法完整读取消息的传输级问题:

[2019-02-14T23:53:52,630][WARN ][o.e.t.n.Netty4Transport  ] [IK-PRD-M3] exception caught on transport layer [[id: 0xd97a9d8c, L:/10.10.1.184:51594 - R:10.10.1.166/10.10.1.166:9300]], closing connection
java.lang.IllegalStateException: Message not fully read (response) for requestId [7719647], handler [org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler/org.elasticsearch.transport.TransportActionProxy$ProxyResponseHandler@7f2fcd88], error [false]; resetting
    at org.elasticsearch.transport.TcpTransport.messageReceived(TcpTransport.java:1399) ~[elasticsearch-5.6.2.jar:5.6.2]
    at org.elasticsearch.transport.netty4.Netty4MessageChannelHandler.channelRead(Netty4MessageChannelHandler.java:74) ~[transport-netty4-5.6.2.jar:5.6.2]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310) [netty-codec-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:297) [netty-codec-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:413) [netty-codec-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265) [netty-codec-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1334) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:926) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:134) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:644) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:544) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:498) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:458) [netty-transport-4.1.13.Final.jar:4.1.13.Final]
    at io.netty.util.concurrent.SingleThreadEventExecutor.run(SingleThreadEventExecutor.java:858) [netty-common-4.1.13.Final.jar:4.1.13.Final]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_74]

然后那个数据节点被丢弃...

[2019-02-14T23:53:52,639][INFO ][o.e.c.s.ClusterService ] [IK-PRD-M3] removed {{IK-PRD-D103}{gAwPc0AvTyGR58ugLQ7K4Q}{-MdtgQHlT4SEQsDYTjvRBw}{10.10.1.166}{10.10.1.166:9300}{ml.max_open_jobs=10, ml.enabled=true, tag=hot},}, reason: zen-disco-node-failed({IK-PRD-D103}{gAwPc0AvTyGR58ugLQ7K4Q}{-MdtgQHlT4SEQsDYTjvRBw}{10.10.1.166}{10.10.1.166:9300}{ml.max_open_jobs=10, ml.enabled=true, tag=hot}), reason(transport disconnected)[{IK-PRD-D103}{gAwPc0AvTyGR58ugLQ7K4Q}{-MdtgQHlT4SEQsDYTjvRBw}{10.10.1.166}{10.10.1.166:9300}{ml.max_open_jobs=10, ml.enabled=true, tag=hot} transport disconnected]

...并在几秒钟后重新添加

[2019-02-14T23:53:58,367][INFO ][o.e.c.s.ClusterService ] [IK-PRD-M3] added {{IK-PRD-D103}{gAwPc0AvTyGR58ugLQ7K4Q}{-MdtgQHlT4SEQsDYTjvRBw}{10.10.1.166}{10.10.1.166:9300}{ml.max_open_jobs=10, ml.enabled=true, tag=hot},}, reason: zen-disco-node-join[{IK-PRD-D103}{gAwPc0AvTyGR58ugLQ7K4Q}{-MdtgQHlT4SEQsDYTjvRBw}{10.10.1.166}{10.10.1.166:9300}{ml.max_open_jobs=10, ml.enabled=true, tag=hot}]

还值得注意的是,集群上和集群上跳出的节点几乎总是相同的三个,其中一个在 CCS 的种子节点列表中。

同意,完全没有迹象表明 CCS 与此有任何关系,但由于这几乎是旧 5.6.2 集群经历的唯一变化,而且其中一个跳跃节点是 CCS网关节点,CCS 造成这种情况的可能性很高。

想到的一件事是将旧的 5.6.2 集群迁移到最新的 5.6.14 补丁版本,但尝试在不稳定的黄色集群上迁移可能会有风险,这就是我们寻求建议的原因这里。

查看 5.6.3 release notes, we see a fix (#26833 fixed by @javanna in PR #27881) 可能会解决我们的问题,但我们不确定是否需要将整个集群迁移到 5.6.3 或仅迁移种子节点。我们尝试的一件事是向 5.6.2 集群添加两个 5.6.3 客户端节点(即不是主节点也不是数据节点)并将它们用作 CCS 的种子节点,但这使集群更加不稳定。所以我们恢复了那个改变,但也许我们没有做正确的事

我们没有在任何其他 5.6 中看到。发行说明修复了可能导致我们所看到的错误的任何内容。我们正在寻求有关如何解决此问题的专家建议,再次感谢您的关注。

注意:这也已发布在 Elasticsearch 官方论坛中:https://discuss.elastic.co/t/shaky-cross-cluster-search-between-6-5-1-and-5-6-2/168518/6

将我们的 5.6.2 集群升级到 5.6.3 确实解决了问题。

我们的集群在过去的几个小时里又变绿了。

感谢 Elastic 支持团队帮助我们查明并解决此问题。