testReopenDuringCloseOnMultipleIndices never intercepts an action #39757
Description
testReopenDuringCloseOnMultipleIndices fails while waiting to intercept a VerifyShardBeforeCloseAction:
REPRODUCE WITH line does not reproduce for me:
./gradlew :server:integTest \
-Dtests.seed=61492C398DCD3D9D \
-Dtests.class=org.elasticsearch.indices.state.ReopenWhileClosingIT \
-Dtests.method="testReopenDuringCloseOnMultipleIndices" \
-Dtests.security.manager=true \
-Dtests.locale=ar-AE \
-Dtests.timezone=JST \
-Dcompiler.java=11 \
-Druntime.java=8
Stack trace:
java.lang.AssertionError: Waiting for index to have a closing blocked
at __randomizedtesting.SeedInfo.seed([61492C398DCD3D9D:C2CE799094E2F96A]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.elasticsearch.indices.state.ReopenWhileClosingIT.testReopenDuringCloseOnMultipleIndices(ReopenWhileClosingIT.java:100)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
The logs do not look staggeringly helpful:
1> [2019-03-06T20:52:48,816][INFO ][o.e.i.s.ReopenWhileClosingIT] [testReopenDuringCloseOnMultipleIndices] before test
1> [2019-03-06T20:52:48,821][INFO ][o.e.i.s.ReopenWhileClosingIT] [testReopenDuringCloseOnMultipleIndices] [ReopenWhileClosingIT#testReopenDuringCloseOnMultipleIndices]: setting up test
1> [2019-03-06T20:52:48,887][INFO ][o.e.t.InternalTestCluster] [testReopenDuringCloseOnMultipleIndices] Setup InternalTestCluster [TEST-CHILD_VM=[7]-CLUSTER_SEED=[-5004444631372515241]-HASH=[1C6B931BB79]-cluster] with seed [BA8CA41F58EE3857] using [0] dedicated masters, [3] (data) nodes and [1] coord only nodes (min_master_nodes are [auto-managed])
1> [2019-03-06T20:52:49,965][INFO ][o.e.e.NodeEnvironment ] [testReopenDuringCloseOnMultipleIndices] using [1] data paths, mounts [[/ (/dev/sda2)]], net usable_space [257.2gb], net total_space [299.6gb], types [xfs]
1> [2019-03-06T20:52:49,966][INFO ][o.e.e.NodeEnvironment ] [testReopenDuringCloseOnMultipleIndices] heap size [491mb], compressed ordinary object pointers [true]
1> [2019-03-06T20:52:49,975][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] node name [node_t0], node ID [ziaYKzDiQN2otelIiAYFgg]
1> [2019-03-06T20:52:49,976][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] version[8.0.0], pid[62909], build[unknown/unknown/Unknown/Unknown], OS[Linux/4.12.14-95.6-default/amd64], JVM[Oracle Corporation/Java HotSpot(TM) 64-Bit Server VM/1.8.0_202/25.202-b08]
1> [2019-03-06T20:52:49,976][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] JVM Home [/var/lib/jenkins/.java/oracle-8u202-linux/jre]
1> [2019-03-06T20:52:49,976][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] JVM arguments [-Dfile.encoding=UTF8, -ea, -esa, -Xmx512m, -Xms512m, -XX:+HeapDumpOnOutOfMemoryError, -XX:HeapDumpPath=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/sles-12/server/build/heapdump, -Dtests.prefix=tests, -Dtests.seed=61492C398DCD3D9D, -Druntime.java=8, -Des.scripting.update.ctx_in_params=false, -Dtests.security.manager=true, -Djava.io.tmpdir=./temp, -Dtests.gradle=true, -Dtests.artifact=server, -Djava.awt.headless=true, -Dcompiler.java=11, -Dtests.task=:server:integTest, -Djna.nosys=true, -Dtests.logger.level=WARN, -Djunit4.childvm.cwd=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/sles-12/server/build/testrun/integTest/J7, -Djunit4.tempDir=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/sles-12/server/build/testrun/integTest/temp, -Djunit4.childvm.id=7, -Djunit4.childvm.count=8]
1> [2019-03-06T20:52:49,989][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] no modules loaded
1> [2019-03-06T20:52:49,990][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.ESIntegTestCase$AssertActionNamePlugin]
1> [2019-03-06T20:52:49,990][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
1> [2019-03-06T20:52:49,991][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.MockHttpTransport$TestPlugin]
1> [2019-03-06T20:52:49,991][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.transport.MockTransportService$TestPlugin]
1> [2019-03-06T20:52:49,991][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
1> [2019-03-06T20:52:53,006][INFO ][o.e.d.DiscoveryModule ] [testReopenDuringCloseOnMultipleIndices] using discovery type [zen] and seed hosts providers [settings, file]
1> [2019-03-06T20:52:53,737][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] initialized
1> [2019-03-06T20:52:53,751][INFO ][o.e.e.NodeEnvironment ] [testReopenDuringCloseOnMultipleIndices] using [1] data paths, mounts [[/ (/dev/sda2)]], net usable_space [257.2gb], net total_space [299.6gb], types [xfs]
1> [2019-03-06T20:52:53,752][INFO ][o.e.e.NodeEnvironment ] [testReopenDuringCloseOnMultipleIndices] heap size [491mb], compressed ordinary object pointers [true]
1> [2019-03-06T20:52:53,754][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] node name [node_t1], node ID [OPeu4Bj_QuauOep5MnijFQ]
1> [2019-03-06T20:52:53,754][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] version[8.0.0], pid[62909], build[unknown/unknown/Unknown/Unknown], OS[Linux/4.12.14-95.6-default/amd64], JVM[Oracle Corporation/Java HotSpot(TM) 64-Bit Server VM/1.8.0_202/25.202-b08]
1> [2019-03-06T20:52:53,754][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] JVM Home [/var/lib/jenkins/.java/oracle-8u202-linux/jre]
1> [2019-03-06T20:52:53,754][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] JVM arguments [-Dfile.encoding=UTF8, -ea, -esa, -Xmx512m, -Xms512m, -XX:+HeapDumpOnOutOfMemoryError, -XX:HeapDumpPath=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/sles-12/server/build/heapdump, -Dtests.prefix=tests, -Dtests.seed=61492C398DCD3D9D, -Druntime.java=8, -Des.scripting.update.ctx_in_params=false, -Dtests.security.manager=true, -Djava.io.tmpdir=./temp, -Dtests.gradle=true, -Dtests.artifact=server, -Djava.awt.headless=true, -Dcompiler.java=11, -Dtests.task=:server:integTest, -Djna.nosys=true, -Dtests.logger.level=WARN, -Djunit4.childvm.cwd=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/sles-12/server/build/testrun/integTest/J7, -Djunit4.tempDir=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/sles-12/server/build/testrun/integTest/temp, -Djunit4.childvm.id=7, -Djunit4.childvm.count=8]
1> [2019-03-06T20:52:53,756][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] no modules loaded
1> [2019-03-06T20:52:53,756][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.ESIntegTestCase$AssertActionNamePlugin]
1> [2019-03-06T20:52:53,758][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
1> [2019-03-06T20:52:53,758][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.MockHttpTransport$TestPlugin]
1> [2019-03-06T20:52:53,758][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.transport.MockTransportService$TestPlugin]
1> [2019-03-06T20:52:53,758][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
1> [2019-03-06T20:52:53,793][INFO ][o.e.d.DiscoveryModule ] [testReopenDuringCloseOnMultipleIndices] using discovery type [zen] and seed hosts providers [settings, file]
1> [2019-03-06T20:52:53,847][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] initialized
1> [2019-03-06T20:52:53,864][INFO ][o.e.e.NodeEnvironment ] [testReopenDuringCloseOnMultipleIndices] using [1] data paths, mounts [[/ (/dev/sda2)]], net usable_space [257.2gb], net total_space [299.6gb], types [xfs]
1> [2019-03-06T20:52:53,865][INFO ][o.e.e.NodeEnvironment ] [testReopenDuringCloseOnMultipleIndices] heap size [491mb], compressed ordinary object pointers [true]
1> [2019-03-06T20:52:53,867][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] node name [node_t2], node ID [9HJWOcwHS7qSMEI37cSLDQ]
1> [2019-03-06T20:52:53,867][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] version[8.0.0], pid[62909], build[unknown/unknown/Unknown/Unknown], OS[Linux/4.12.14-95.6-default/amd64], JVM[Oracle Corporation/Java HotSpot(TM) 64-Bit Server VM/1.8.0_202/25.202-b08]
1> [2019-03-06T20:52:53,867][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] JVM Home [/var/lib/jenkins/.java/oracle-8u202-linux/jre]
1> [2019-03-06T20:52:53,868][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] JVM arguments [-Dfile.encoding=UTF8, -ea, -esa, -Xmx512m, -Xms512m, -XX:+HeapDumpOnOutOfMemoryError, -XX:HeapDumpPath=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/sles-12/server/build/heapdump, -Dtests.prefix=tests, -Dtests.seed=61492C398DCD3D9D, -Druntime.java=8, -Des.scripting.update.ctx_in_params=false, -Dtests.security.manager=true, -Djava.io.tmpdir=./temp, -Dtests.gradle=true, -Dtests.artifact=server, -Djava.awt.headless=true, -Dcompiler.java=11, -Dtests.task=:server:integTest, -Djna.nosys=true, -Dtests.logger.level=WARN, -Djunit4.childvm.cwd=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/sles-12/server/build/testrun/integTest/J7, -Djunit4.tempDir=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/sles-12/server/build/testrun/integTest/temp, -Djunit4.childvm.id=7, -Djunit4.childvm.count=8]
1> [2019-03-06T20:52:53,869][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] no modules loaded
1> [2019-03-06T20:52:53,873][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.ESIntegTestCase$AssertActionNamePlugin]
1> [2019-03-06T20:52:53,873][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
1> [2019-03-06T20:52:53,874][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.MockHttpTransport$TestPlugin]
1> [2019-03-06T20:52:53,874][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.transport.MockTransportService$TestPlugin]
1> [2019-03-06T20:52:53,874][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
1> [2019-03-06T20:52:53,962][INFO ][o.e.d.DiscoveryModule ] [testReopenDuringCloseOnMultipleIndices] using discovery type [zen] and seed hosts providers [settings, file]
1> [2019-03-06T20:52:54,024][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] initialized
1> [2019-03-06T20:52:54,043][INFO ][o.e.e.NodeEnvironment ] [testReopenDuringCloseOnMultipleIndices] using [1] data paths, mounts [[/ (/dev/sda2)]], net usable_space [257.2gb], net total_space [299.6gb], types [xfs]
1> [2019-03-06T20:52:54,043][INFO ][o.e.e.NodeEnvironment ] [testReopenDuringCloseOnMultipleIndices] heap size [491mb], compressed ordinary object pointers [true]
1> [2019-03-06T20:52:54,046][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] node name [node_tc3], node ID [cubyT3bwQyCCEMUF2sbUcA]
1> [2019-03-06T20:52:54,046][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] version[8.0.0], pid[62909], build[unknown/unknown/Unknown/Unknown], OS[Linux/4.12.14-95.6-default/amd64], JVM[Oracle Corporation/Java HotSpot(TM) 64-Bit Server VM/1.8.0_202/25.202-b08]
1> [2019-03-06T20:52:54,046][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] JVM Home [/var/lib/jenkins/.java/oracle-8u202-linux/jre]
1> [2019-03-06T20:52:54,047][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] JVM arguments [-Dfile.encoding=UTF8, -ea, -esa, -Xmx512m, -Xms512m, -XX:+HeapDumpOnOutOfMemoryError, -XX:HeapDumpPath=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/sles-12/server/build/heapdump, -Dtests.prefix=tests, -Dtests.seed=61492C398DCD3D9D, -Druntime.java=8, -Des.scripting.update.ctx_in_params=false, -Dtests.security.manager=true, -Djava.io.tmpdir=./temp, -Dtests.gradle=true, -Dtests.artifact=server, -Djava.awt.headless=true, -Dcompiler.java=11, -Dtests.task=:server:integTest, -Djna.nosys=true, -Dtests.logger.level=WARN, -Djunit4.childvm.cwd=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/sles-12/server/build/testrun/integTest/J7, -Djunit4.tempDir=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/sles-12/server/build/testrun/integTest/temp, -Djunit4.childvm.id=7, -Djunit4.childvm.count=8]
1> [2019-03-06T20:52:54,047][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] no modules loaded
1> [2019-03-06T20:52:54,048][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.ESIntegTestCase$AssertActionNamePlugin]
1> [2019-03-06T20:52:54,048][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
1> [2019-03-06T20:52:54,048][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.MockHttpTransport$TestPlugin]
1> [2019-03-06T20:52:54,048][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.test.transport.MockTransportService$TestPlugin]
1> [2019-03-06T20:52:54,048][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
1> [2019-03-06T20:52:54,130][INFO ][o.e.d.DiscoveryModule ] [testReopenDuringCloseOnMultipleIndices] using discovery type [zen] and seed hosts providers [settings, file]
1> [2019-03-06T20:52:54,214][INFO ][o.e.n.Node ] [testReopenDuringCloseOnMultipleIndices] initialized
1> [2019-03-06T20:52:54,337][INFO ][o.e.n.Node ] [[test_TEST-CHILD_VM=[7]-CLUSTER_SEED=[-5004444631372515241]-HASH=[1C6B931BB79]-cluster[T#1]]] starting ...
1> [2019-03-06T20:52:54,346][INFO ][o.e.n.Node ] [[test_TEST-CHILD_VM=[7]-CLUSTER_SEED=[-5004444631372515241]-HASH=[1C6B931BB79]-cluster[T#2]]] starting ...
1> [2019-03-06T20:52:54,419][INFO ][o.e.n.Node ] [[test_TEST-CHILD_VM=[7]-CLUSTER_SEED=[-5004444631372515241]-HASH=[1C6B931BB79]-cluster[T#4]]] starting ...
1> [2019-03-06T20:52:54,419][INFO ][o.e.n.Node ] [[test_TEST-CHILD_VM=[7]-CLUSTER_SEED=[-5004444631372515241]-HASH=[1C6B931BB79]-cluster[T#3]]] starting ...
1> [2019-03-06T20:52:54,786][INFO ][o.e.t.TransportService ] [[test_TEST-CHILD_VM=[7]-CLUSTER_SEED=[-5004444631372515241]-HASH=[1C6B931BB79]-cluster[T#4]]] publish_address {127.0.0.1:38783}, bound_addresses {[::1]:40893}, {127.0.0.1:38783}
1> [2019-03-06T20:52:54,913][INFO ][o.e.t.TransportService ] [[test_TEST-CHILD_VM=[7]-CLUSTER_SEED=[-5004444631372515241]-HASH=[1C6B931BB79]-cluster[T#1]]] publish_address {127.0.0.1:36477}, bound_addresses {[::1]:33207}, {127.0.0.1:36477}
1> [2019-03-06T20:52:54,924][INFO ][o.e.t.TransportService ] [[test_TEST-CHILD_VM=[7]-CLUSTER_SEED=[-5004444631372515241]-HASH=[1C6B931BB79]-cluster[T#3]]] publish_address {127.0.0.1:37809}, bound_addresses {[::1]:38185}, {127.0.0.1:37809}
1> [2019-03-06T20:52:54,924][INFO ][o.e.t.TransportService ] [[test_TEST-CHILD_VM=[7]-CLUSTER_SEED=[-5004444631372515241]-HASH=[1C6B931BB79]-cluster[T#2]]] publish_address {127.0.0.1:34975}, bound_addresses {[::1]:42029}, {127.0.0.1:34975}
1> [2019-03-06T20:52:55,688][INFO ][o.e.c.c.Coordinator ] [node_t1] setting initial configuration to VotingConfiguration{ziaYKzDiQN2otelIiAYFgg,{bootstrap-placeholder}-node_t2,OPeu4Bj_QuauOep5MnijFQ}
1> [2019-03-06T20:52:55,933][INFO ][o.e.c.s.MasterService ] [node_t1] elected-as-master ([3] nodes joined)[{node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975} elect leader, {node_t2}{9HJWOcwHS7qSMEI37cSLDQ}{51uuIPnBQMK2IR6eneENnQ}{127.0.0.1}{127.0.0.1:37809} elect leader, {node_t0}{ziaYKzDiQN2otelIiAYFgg}{Fm0FHQy1TJaIrEm5Y2nywA}{127.0.0.1}{127.0.0.1:36477} elect leader, _BECOME_MASTER_TASK_, _FINISH_ELECTION_], term: 1, version: 1, reason: master node changed {previous [], current [{node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975}]}, added {{node_t2}{9HJWOcwHS7qSMEI37cSLDQ}{51uuIPnBQMK2IR6eneENnQ}{127.0.0.1}{127.0.0.1:37809},{node_t0}{ziaYKzDiQN2otelIiAYFgg}{Fm0FHQy1TJaIrEm5Y2nywA}{127.0.0.1}{127.0.0.1:36477},}
1> [2019-03-06T20:52:56,021][INFO ][o.e.c.s.ClusterApplierService] [node_t2] master node changed {previous [], current [{node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975}]}, added {{node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975},{node_t0}{ziaYKzDiQN2otelIiAYFgg}{Fm0FHQy1TJaIrEm5Y2nywA}{127.0.0.1}{127.0.0.1:36477},}, term: 1, version: 1, reason: ApplyCommitRequest{term=1, version=1, sourceNode={node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975}}
1> [2019-03-06T20:52:56,021][INFO ][o.e.c.s.ClusterApplierService] [node_t0] master node changed {previous [], current [{node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975}]}, added {{node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975},{node_t2}{9HJWOcwHS7qSMEI37cSLDQ}{51uuIPnBQMK2IR6eneENnQ}{127.0.0.1}{127.0.0.1:37809},}, term: 1, version: 1, reason: ApplyCommitRequest{term=1, version=1, sourceNode={node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975}}
1> [2019-03-06T20:52:56,026][INFO ][o.e.n.Node ] [[test_TEST-CHILD_VM=[7]-CLUSTER_SEED=[-5004444631372515241]-HASH=[1C6B931BB79]-cluster[T#1]]] started
1> [2019-03-06T20:52:56,027][INFO ][o.e.n.Node ] [[test_TEST-CHILD_VM=[7]-CLUSTER_SEED=[-5004444631372515241]-HASH=[1C6B931BB79]-cluster[T#3]]] started
1> [2019-03-06T20:52:56,032][INFO ][o.e.c.s.ClusterApplierService] [node_t1] master node changed {previous [], current [{node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975}]}, added {{node_t2}{9HJWOcwHS7qSMEI37cSLDQ}{51uuIPnBQMK2IR6eneENnQ}{127.0.0.1}{127.0.0.1:37809},{node_t0}{ziaYKzDiQN2otelIiAYFgg}{Fm0FHQy1TJaIrEm5Y2nywA}{127.0.0.1}{127.0.0.1:36477},}, term: 1, version: 1, reason: Publication{term=1, version=1}
1> [2019-03-06T20:52:56,048][INFO ][o.e.n.Node ] [[test_TEST-CHILD_VM=[7]-CLUSTER_SEED=[-5004444631372515241]-HASH=[1C6B931BB79]-cluster[T#2]]] started
1> [2019-03-06T20:52:56,197][INFO ][o.e.g.GatewayService ] [node_t1] recovered [0] indices into cluster_state
1> [2019-03-06T20:52:56,198][INFO ][o.e.c.s.MasterService ] [node_t1] node-join[{node_tc3}{cubyT3bwQyCCEMUF2sbUcA}{UPxmcCKnS5yTB0NZEcUS4g}{127.0.0.1}{127.0.0.1:38783} join existing leader], term: 1, version: 4, reason: added {{node_tc3}{cubyT3bwQyCCEMUF2sbUcA}{UPxmcCKnS5yTB0NZEcUS4g}{127.0.0.1}{127.0.0.1:38783},}
1> [2019-03-06T20:52:56,232][INFO ][o.e.c.s.ClusterApplierService] [node_t0] added {{node_tc3}{cubyT3bwQyCCEMUF2sbUcA}{UPxmcCKnS5yTB0NZEcUS4g}{127.0.0.1}{127.0.0.1:38783},}, term: 1, version: 4, reason: ApplyCommitRequest{term=1, version=4, sourceNode={node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975}}
1> [2019-03-06T20:52:56,232][INFO ][o.e.c.s.ClusterApplierService] [node_tc3] master node changed {previous [], current [{node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975}]}, added {{node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975},{node_t0}{ziaYKzDiQN2otelIiAYFgg}{Fm0FHQy1TJaIrEm5Y2nywA}{127.0.0.1}{127.0.0.1:36477},{node_t2}{9HJWOcwHS7qSMEI37cSLDQ}{51uuIPnBQMK2IR6eneENnQ}{127.0.0.1}{127.0.0.1:37809},}, term: 1, version: 4, reason: ApplyCommitRequest{term=1, version=4, sourceNode={node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975}}
1> [2019-03-06T20:52:56,243][INFO ][o.e.n.Node ] [[test_TEST-CHILD_VM=[7]-CLUSTER_SEED=[-5004444631372515241]-HASH=[1C6B931BB79]-cluster[T#4]]] started
1> [2019-03-06T20:52:56,249][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] no modules loaded
1> [2019-03-06T20:52:56,249][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
1> [2019-03-06T20:52:56,250][INFO ][o.e.c.s.ClusterApplierService] [node_t2] added {{node_tc3}{cubyT3bwQyCCEMUF2sbUcA}{UPxmcCKnS5yTB0NZEcUS4g}{127.0.0.1}{127.0.0.1:38783},}, term: 1, version: 4, reason: ApplyCommitRequest{term=1, version=4, sourceNode={node_t1}{OPeu4Bj_QuauOep5MnijFQ}{NLSoooHvSqGeBR_MnUCNzQ}{127.0.0.1}{127.0.0.1:34975}}
1> [2019-03-06T20:52:56,257][INFO ][o.e.c.s.ClusterApplierService] [node_t1] added {{node_tc3}{cubyT3bwQyCCEMUF2sbUcA}{UPxmcCKnS5yTB0NZEcUS4g}{127.0.0.1}{127.0.0.1:38783},}, term: 1, version: 4, reason: Publication{term=1, version=4}
1> [2019-03-06T20:52:56,370][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] no modules loaded
1> [2019-03-06T20:52:56,370][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
1> [2019-03-06T20:52:56,476][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] no modules loaded
1> [2019-03-06T20:52:56,477][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
1> [2019-03-06T20:52:56,986][INFO ][o.e.c.m.MetaDataIndexTemplateService] [node_t1] adding template [random_index_template] for index patterns [*]
1> [2019-03-06T20:52:57,014][INFO ][o.e.i.s.ReopenWhileClosingIT] [testReopenDuringCloseOnMultipleIndices] [ReopenWhileClosingIT#testReopenDuringCloseOnMultipleIndices]: all set up test
1> [2019-03-06T20:52:57,025][INFO ][o.e.i.s.ReopenWhileClosingIT] [testReopenDuringCloseOnMultipleIndices] using custom data_path for index: [WDCGtiLIlP]
1> [2019-03-06T20:52:57,057][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_t1] [index-0] creating index, cause [api], templates [random_index_template], shards [3]/[1], mappings []
1> [2019-03-06T20:52:58,191][INFO ][o.e.c.m.MetaDataMappingService] [node_t1] [index-0/XMwkmmWySsuvza4NDUuP1w] create_mapping [_doc]
1> [2019-03-06T20:52:58,439][INFO ][o.e.c.r.a.AllocationService] [node_t1] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[index-0][2], [index-0][1]] ...]).
1> [2019-03-06T20:52:58,693][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] no modules loaded
1> [2019-03-06T20:52:58,693][INFO ][o.e.p.PluginsService ] [testReopenDuringCloseOnMultipleIndices] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
1> [2019-03-06T20:52:59,767][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_t1] [index-1] creating index, cause [api], templates [random_index_template], shards [4]/[0], mappings []
1> [2019-03-06T20:52:59,962][INFO ][o.e.c.r.a.AllocationService] [node_t1] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[index-1][0], [index-1][3], [index-1][1]] ...]).
1> [2019-03-06T20:53:00,044][INFO ][o.e.c.m.MetaDataMappingService] [node_t1] [index-1/_SU3Wq5yTNyLegmqbPoUdA] create_mapping [_doc]
1> [2019-03-06T20:53:00,337][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_t1] [index-2] creating index, cause [api], templates [random_index_template], shards [2]/[1], mappings []
1> [2019-03-06T20:53:00,514][INFO ][o.e.c.m.MetaDataMappingService] [node_t1] [index-2/5DgsVrMVQw2xB6rhJRTCCg] create_mapping [_doc]
1> [2019-03-06T20:53:01,055][INFO ][o.e.c.r.a.AllocationService] [node_t1] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[index-2][0]] ...]).
1> [2019-03-06T20:53:01,624][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_t1] [index-3] creating index, cause [api], templates [random_index_template], shards [6]/[0], mappings []
1> [2019-03-06T20:53:01,931][INFO ][o.e.c.r.a.AllocationService] [node_t1] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[index-3][1], [index-3][3], [index-3][0]] ...]).
1> [2019-03-06T20:53:01,953][INFO ][o.e.c.m.MetaDataMappingService] [node_t1] [index-3/v-k83F6cRlmtInSp9zc5nQ] create_mapping [_doc]
1> [2019-03-06T20:53:02,048][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_t1] [index-4] creating index, cause [api], templates [random_index_template], shards [6]/[1], mappings []
1> [2019-03-06T20:53:02,396][INFO ][o.e.c.m.MetaDataMappingService] [node_t1] [index-4/kwp0nV5ZQ1GLpvBHrtFQtQ] create_mapping [_doc]
1> [2019-03-06T20:53:02,840][INFO ][o.e.c.r.a.AllocationService] [node_t1] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[index-4][0]] ...]).
1> [2019-03-06T20:53:03,191][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_t1] [index-5] creating index, cause [api], templates [random_index_template], shards [3]/[0], mappings []
1> [2019-03-06T20:53:03,452][INFO ][o.e.c.r.a.AllocationService] [node_t1] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[index-5][0]] ...]).
1> [2019-03-06T20:53:03,487][INFO ][o.e.c.m.MetaDataMappingService] [node_t1] [index-5/MTxjCjaITXaKBMYTTDYPjg] create_mapping [_doc]
1> [2019-03-06T20:53:03,575][INFO ][o.e.c.m.MetaDataCreateIndexService] [node_t1] [index-6] creating index, cause [api], templates [random_index_template], shards [10]/[1], mappings []
1> [2019-03-06T20:53:03,989][INFO ][o.e.c.m.MetaDataMappingService] [node_t1] [index-6/7O8wwQG3Q2-gzWgvuWovlQ] create_mapping [_doc]
1> [2019-03-06T20:53:04,491][INFO ][o.e.c.r.a.AllocationService] [node_t1] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[index-6][8], [index-6][3]] ...]).
1> [2019-03-06T20:53:04,854][INFO ][o.e.c.m.MetaDataIndexStateService] [node_t1] closing indices [index-4/kwp0nV5ZQ1GLpvBHrtFQtQ],[index-1/_SU3Wq5yTNyLegmqbPoUdA],[index-2/5DgsVrMVQw2xB6rhJRTCCg],[index-0/XMwkmmWySsuvza4NDUuP1w],[index-6/7O8wwQG3Q2-gzWgvuWovlQ],[index-5/MTxjCjaITXaKBMYTTDYPjg],[index-3/v-k83F6cRlmtInSp9zc5nQ]
1> [2019-03-06T20:53:05,102][INFO ][o.e.c.m.MetaDataIndexStateService] [node_t1] completed closing of indices [index-0, index-1, index-2, index-3, index-4, index-5, index-6]
1> [2019-03-06T20:53:06,692][INFO ][o.e.c.r.a.AllocationService] [node_t1] Cluster health status changed from [RED] to [YELLOW] (reason: [shards started [[index-6][9], [index-6][7], [index-6][4], [index-4][3], [index-6][5], [index-6][3], [index-1][1]] ...]).
1> [2019-03-06T20:53:07,007][INFO ][o.e.c.r.a.AllocationService] [node_t1] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[index-0][0], [index-2][0], [index-0][2]] ...]).
1> [2019-03-06T20:54:04,838][INFO ][o.e.i.s.ReopenWhileClosingIT] [testReopenDuringCloseOnMultipleIndices] [ReopenWhileClosingIT#testReopenDuringCloseOnMultipleIndices]: cleaning up after test