[CI] RareClusterStateIT testDelayedMappingPropagationOnReplica failing

[pgomulka]

Build scan:
https://gradle-enterprise.elastic.co/s/hmt34pcxbhwja/tests/:server:internalClusterTest/org.elasticsearch.cluster.coordination.RareClusterStateIT/testDelayedMappingPropagationOnReplica

Reproduction line:
./gradlew ':server:internalClusterTest' --tests "org.elasticsearch.cluster.coordination.RareClusterStateIT.testDelayedMappingPropagationOnReplica" -Dtests.seed=E2A1EC86CEE80019 -Dtests.locale=zh-CN -Dtests.timezone=PNT -Druntime.java=17

Applicable branches:
main

Reproduces locally?:
No

Failure history:
https://gradle-enterprise.elastic.co/scans/tests?tests.container=org.elasticsearch.cluster.coordination.RareClusterStateIT&tests.test=testDelayedMappingPropagationOnReplica

Failure excerpt:

java.lang.AssertionError: (No message provided)

  at __randomizedtesting.SeedInfo.seed([E2A1EC86CEE80019:9EDF2D499E0F3BFA]:0)
  at org.junit.Assert.fail(Assert.java:86)
  at org.junit.Assert.assertTrue(Assert.java:41)
  at org.junit.Assert.assertFalse(Assert.java:64)
  at org.junit.Assert.assertFalse(Assert.java:74)
  at org.elasticsearch.cluster.coordination.RareClusterStateIT.testDelayedMappingPropagationOnReplica(RareClusterStateIT.java:405)
  at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-2)
  at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
  at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
  at java.lang.reflect.Method.invoke(Method.java:568)
  at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1758)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:946)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:982)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:996)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at org.apache.lucene.tests.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:44)
  at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
  at org.apache.lucene.tests.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:45)
  at org.apache.lucene.tests.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:60)
  at org.apache.lucene.tests.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:44)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:390)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:843)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:490)
  at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:955)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:840)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:891)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:902)
  at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at org.apache.lucene.tests.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:38)
  at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
  at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at org.apache.lucene.tests.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
  at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
  at org.apache.lucene.tests.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:44)
  at org.apache.lucene.tests.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:60)
  at org.apache.lucene.tests.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:47)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:390)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:850)
  at java.lang.Thread.run(Thread.java:833)

[elasticsearchmachine]

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

[iverase]

another case in 8.5: https://gradle-enterprise.elastic.co/s/7c6p3ahcjzvga

[pxsalehi]

I can reproduce this now. I'll work on a fix!

[pxsalehi]

hmm... Running it with DEBUG, it seems even though the node with the replica shard is supposed to be kept from receiving cluster state updates using BlockClusterStateProcessing, it still applies some cluster state update with some lag, which I guess completes the PutMapping request.

[2022-09-29T19:22:33,198][DEBUG][o.e.c.s.MasterService    ] [node_t1] ack received from node [{node_t0}{eZLI7-THQ9SZFYCaV2csmg}{9TkzWezNRM6baoakV6nyLQ}{node_t0}{127.0.0.1}{127.0.0.1:13301}{cdfhilmrstw}], cluster_state update (version: 10)
org.elasticsearch.cluster.coordination.CoordinationStateRejectedException: incoming version 10 does not match current version 11
	at org.elasticsearch.cluster.coordination.CoordinationState.handleCommit(CoordinationState.java:493) ~[classes/:?]
	at org.elasticsearch.cluster.coordination.Coordinator.handleApplyCommit(Coordinator.java:391) ~[classes/:?]
	at org.elasticsearch.cluster.coordination.Coordinator.lambda$new$1(Coordinator.java:261) ~[classes/:?]
	at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:71) ~[classes/:?]
	at org.elasticsearch.transport.InboundHandler$1.doRun(InboundHandler.java:291) ~[classes/:?]
	at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:892) ~[classes/:?]
	at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26) ~[classes/:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
	at java.lang.Thread.run(Thread.java:833) ~[?:?]

[DaveCTurner]

I haven't been able to reproduce this locally after several thousand iterations, and I'm struggling to join the dots on the explanation given above. I have opened #91272 to reinstate the reverted commit and add some more logging to investigate further.

[DaveCTurner]

We identified the problem and updated #91272 to address it, so I'm closing this again.