active masternode crash caused by datanode Input/output error

[hanbj]

Problem description：
A few days ago, an active masternode process of the cluster hung up. Looking at the log, it was found that a datanode disk was damaged. The log is as follows:

[2021-08-09T09:17:36,992][WARN ][o.e.g.G.InternalPrimaryShardAllocator][node1] [index_2021-08-07][3]: failed to list shard for shard_started on node [Jyd9FdobRayRSGEdQla3Ww]
org.elasticsearch.action.FailedNodeException: Failed node [Jyd9FdobRayRSGEdQla3Ww]
at org.elasticsearch.action.support.nodes.TransportNodesAction$AsyncAction.onFailure(TransportNodesAction.java:221) [elasticsearch-7.6.0.jar:7.6.0]
...
at java.lang.Thread.run(Thread.java:834) [?:?]
Caused by: org.elasticsearch.transport.RemoteTransportException: [node1][0.0.0.0:9300][internal:gateway/local/started_shards[n]]
Caused by: org.elasticsearch.ElasticsearchException: failed to load started shards
at org.elasticsearch.gateway.TransportNodesListGatewayStartedShards.nodeOperation(TransportNodesListGatewayStartedShards.java:168) ~[elasticsearch-7.6.0.jar:7.6.0]
...
at java.lang.Thread.run(Thread.java:834) ~[?:?]
Caused by: java.lang.IllegalStateException: environment is not locked
at org.elasticsearch.env.NodeEnvironment.assertEnvIsLocked(NodeEnvironment.java:1044) ~[elasticsearch-7.6.0.jar:7.6.0]
...
at java.lang.Thread.run(Thread.java:834) ~[?:?]
Caused by: java.io.IOException: Input/output error
at sun.nio.ch.FileDispatcherImpl.size0(Native Method) ~[?:?]
...
at java.lang.Thread.run(Thread.java:834) ~[?:?]

[2021-08-09T09:17:37,291][ERROR][o.e.b.ElasticsearchUncaughtExceptionHandler][node1] fatal error in thread [elasticsearch[node1][masterService#updateTask][T#436]], exiting
java.lang.StackOverflowError: null
at java.util.Collections$UnmodifiableCollection$1.(Collections.java:1042) ~[?:?]
at java.util.Collections$UnmodifiableCollection.iterator(Collections.java:1041) ~[?:?]
at java.util.Collections$UnmodifiableCollection$1.(Collections.java:1042) ~[?:?]
...
at java.util.Collections$UnmodifiableCollection.iterator(Collections.java:1041) ~[?:?]
at java.util.Collections$UnmodifiableCollection$1.(Collections.java:1042) ~[?:?]
at java.util.Collections$UnmodifiableCollection.iterator(Collections.java:1041) ~[?:?]

Here is the code for the UnmodifiableCollection class from Java.
As you can see, when you call iterator to an immutable collection, it creates an instance on the anonymous class. The constructor of this class calls C. iterator ()... Where is the class wrapped in C. However, a stack trace means that it C itself is an immutable collection.

So I can think of a reasonable reason:

If your application is wrapping unmodifiable collections in unmodifiable collections to N levels, then creating an iterator will result in N * 2 levels of stack frames. For large enough N, that would lead to a stack overflow.

static class UnmodifiableCollection<E> implements Collection<E>, Serializable {
        final Collection<? extends E> c;
        UnmodifiableCollection(Collection<? extends E> c) {
            if (c==null)
                throw new NullPointerException();
            this.c = c;
        }
        ...
        public Iterator<E> iterator() {
            return new Iterator<E>() {
                private final Iterator<? extends E> i = c.iterator();

                public boolean hasNext() {return i.hasNext();}
                public E next()          {return i.next();}
                public void remove() {
                    throw new UnsupportedOperationException();
                }
                @Override
                public void forEachRemaining(Consumer<? super E> action) {
                    // Use backing collection version
                    i.forEachRemaining(action);
                }
            };
        }
}

Cause of problem：

Use Arthas to observe the calling path of the iterator method. The command is as follows:

1. options unsafe true
2. stack java.util.Collections$UnmodifiableCollection iterator

The following results will appear only when the process has just started and the above command is executed immediately using Arthas.

ts=2021-08-13 10:10:53;thread_name=elasticsearch[node1][masterService#updateTask][T#1];id=22;is_daemon=true;priority=5;TCCL=jdk.internal.loader.ClassLoaders$AppClassLoader@277050dc
@java.util.Collections$UnmodifiableCollection.iterator()
at java.util.Collections$UnmodifiableCollection$1.(Collections.java:1044)
at java.util.Collections$UnmodifiableCollection.iterator(Collections.java:1043)
...
at java.util.Collections$UnmodifiableCollection$1.(Collections.java:1044)
at java.util.Collections$UnmodifiableCollection.iterator(Collections.java:1043)
at org.elasticsearch.common.io.stream.StreamOutput.writeCollection(StreamOutput.java:1112)
at org.elasticsearch.cluster.routing.**UnassignedInfo.writeTo(**UnassignedInfo.java:297)
at org.elasticsearch.common.io.stream.StreamOutput.writeOptionalWriteable(StreamOutput.java:897)
at org.elasticsearch.cluster.routing.ShardRouting.writeToThin(ShardRouting.java:299)
at org.elasticsearch.cluster.routing.IndexShardRoutingTable$Builder.writeToThin(IndexShardRoutingTable.java:742)
at org.elasticsearch.cluster.routing.IndexRoutingTable.writeTo(IndexRoutingTable.java:321)
at org.elasticsearch.cluster.AbstractDiffable$CompleteDiff.writeTo(AbstractDiffable.java:81)
at org.elasticsearch.cluster.DiffableUtils$DiffableValueSerializer.writeDiff(DiffableUtils.java:647)
...
at org.elasticsearch.cluster.service.TaskBatcher.runIfNotProcessed(TaskBatcher.java:175)
at org.elasticsearch.cluster.service.TaskBatcher$BatchedTask.run(TaskBatcher.java:253)
at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingRunnable.run(ThreadContext.java:633)

Read the source code. Because the datanode disk is damaged, in active masternode BaseGatewayShardAllocator#makeAllocationDecision() method will return AllocateunassignedDecision. no (...), and this shard will be removeAndIgnore. When changing the reason why the shard is not allocated, call UnassignedInfo#getFailedNodeIds() to obtain an immutable collection, In the construction method of UnassignedInfo, a layer of immutable collection failedNodeIds will be wrapped, which cannot be changed.

--GatewayAllocator
------GatewayAllocator#allocateUnassigned()
----------GatewayAllocator#innerAllocatedUnassigned()
--------------BaseGatewayShardAllocator#allocateUnassigned()
------------------UnassignedIterator#removeAndIgnore()
----------------------UnassignedShards#ignoreShard() #currInfo.getFailedNodeIds() will get an immutable collection
--------------------------new UnassignedInfo() #this.failedNodeIds = Collections.unmodifiableSet(failedNodeIds)

Therefore, when the disk is damaged and does not come out for a period of time, it will cause stack overflow.

[elasticmachine]

Pinging @elastic/es-distributed (Team:Distributed)

[original-brownbear]

Thanks for the contribution @hanbj. I looked into this a little an we do indeed even during normal operation wrap this set a couple of times. Just a quick suggestion on making this shorter.

[original-brownbear]

I think we can just use Set.copyOf( here to be shorter and have a singleton for the empty case.

[hanbj]

@original-brownbear Thank you very much for your suggestion. I see that the Set.copyOf() method is not public, and I use jdk14 to test the method, which also reports an error.

[original-brownbear]

Not sure what you mean. java.util.Set#copyOf is available from JDK 10 and public. In master we do not support any JDK version older than 10 so it's not a problem there and for the 7.x backport we do have a wrapper in place that we can use. We use that utility all over the codebase and I don't see a reason why it wouldn't work here?

[hanbj]

@original-brownbear Yes, you're right. Thank you very much. You're great. I've solved it.

[original-brownbear]

LGTM thanks for finding and tracking this down @hanbj ! I'll merge and backport this once green

[original-brownbear]

Jenkins test this

[original-brownbear]

Jenkins run elasticsearch-ci/rest-compatibility

[original-brownbear]

@hanbj seems like we have some backwards compatibility issues here from recent changes, could you merge latest master into your branch again to fix them so we get a clean CI build? Thanks!

[hanbj]

@original-brownbear OK, Thanks, I've handled it. Please try again.

[original-brownbear]

Jenkins test this

[original-brownbear]

np + Thanks again @hanbj !