opensearch-project / OpenSearch

🔎 Open source distributed and RESTful search engine.
https://opensearch.org/docs/latest/opensearch/index/
Apache License 2.0
9.77k stars 1.82k forks source link

[BUG] org.opensearch.cluster.SpecificClusterManagerNodesIT.testElectOnlyBetweenClusterManagerNodes is flaky #16015

Open kkewwei opened 1 month ago

kkewwei commented 1 month ago

Describe the bug

Test org.opensearch.cluster.SpecificClusterManagerNodesIT.testElectOnlyBetweenClusterManagerNodes is flaky

https://build.ci.opensearch.org/job/gradle-check/48160/testReport/junit/org.opensearch.cluster/SpecificClusterManagerNodesIT/testElectOnlyBetweenClusterManagerNodes/

Related component

Cluster Manager

To Reproduce

REPRODUCE WITH:

./gradlew ':server:internalClusterTest' --tests "org.opensearch.cluster.SpecificClusterManagerNodesIT.testElectOnlyBetweenClusterManagerNodes" -Dtests.seed=7C9E59D13B1A1CA3 -Dtests.security.manager=true -Dtests.jvm.argline="-XX:TieredStopAtLevel=1 -XX:ReservedCodeCacheSize=64m" -Dtests.locale=az-Cyrl-AZ -Dtests.timezone=Asia/Almaty -Druntime.java=21

/Library/Java/JavaVirtualMachines/jdk-15.0.2.jdk/Contents/Home/bin/java -ea -Djava.locale.providers=SPI,CLDR -Didea.test.cyclic.buffer.size=1048576 -javaagent:/Applications/IntelliJ IDEA 4.app/Contents/lib/idea_rt.jar=60199:/Applications/IntelliJ IDEA 4.app/Contents/bin -Dfile.encoding=UTF-8 -classpath /Applications/IntelliJ IDEA 4.app/Contents/lib/idea_rt.jar:/Applications/IntelliJ IDEA 4.app/Contents/plugins/junit/lib/junit5-rt.jar:/Applications/IntelliJ IDEA 4.app/Contents/plugins/junit/lib/junit-rt.jar:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/server/out/test/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/server/out/test/resources:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/server/out/production/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/server/out/production/resources:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/compress/out/production/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/compress/out/production/resources:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/x-content/out/production/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/x-content/out/production/resources:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/test/framework/out/production/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/test/framework/out/production/resources:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/core/out/production/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/core/out/production/resources:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/telemetry/out/production/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/task-commons/out/production/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/cli/out/production/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/common/out/production/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/common/out/production/resources:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/secure-sm/out/production/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/geo/out/production/classes:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-core/9.12.0-snapshot-847316d/51ff4940eb1024184bbaa5dae39695d2392c5bab/lucene-core-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-analysis-common/9.12.0-snapshot-847316d/7e282aab7388efc911348f1eacd90e661580dda7/lucene-analysis-common-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-backward-codecs/9.12.0-snapshot-847316d/69e59ba4bed4c58836d2727d72b7f0095d2dcb92/lucene-backward-codecs-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-grouping/9.12.0-snapshot-847316d/5847a7d47f13ecb7f039fb9adf6f3b8e4bddde77/lucene-grouping-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-highlighter/9.12.0-snapshot-847316d/7cc0a26777a479f06fbcfae7abc23e784e1a00dc/lucene-highlighter-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-join/9.12.0-snapshot-847316d/9cd99401c826d910da3c2beab8e42f1af8be6ea4/lucene-join-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-memory/9.12.0-snapshot-847316d/cfee136ecbc3df7adc38b38e020dca5e61c22773/lucene-memory-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-misc/9.12.0-snapshot-847316d/afbc5adf93d4eb1a1b109ad828d1968bf16ef292/lucene-misc-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-queries/9.12.0-snapshot-847316d/16907c36f6adb8ba8f260e05738c66afb37c72d3/lucene-queries-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-queryparser/9.12.0-snapshot-847316d/72baa9bddcf2efb71ffb695f1e9f548699ec13a0/lucene-queryparser-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-sandbox/9.12.0-snapshot-847316d/dd3c63066f583d90b563ebaa6fbe61c603403acb/lucene-sandbox-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-spatial-extras/9.12.0-snapshot-847316d/69b99530e0b05251c12863bee6a9325cafd5fdaa/lucene-spatial-extras-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-spatial3d/9.12.0-snapshot-847316d/a67d193b4b08790169db7cf005a2429991260287/lucene-spatial3d-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-suggest/9.12.0-snapshot-847316d/7a1625ae39071ccbfb3af11df5a74291758f4b47/lucene-suggest-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/joda-time/joda-time/2.12.7/d015b997eccd511e5567218a51651ff0625f6f25/joda-time-2.12.7.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/com.tdunning/t-digest/3.3/5e96c4fd7d63b05828cf5ef41da20649195b1b78/t-digest-3.3.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.hdrhistogram/HdrHistogram/2.2.2/7959933ebcc0f05b2eaa5af0a0c8689fa257b15c/HdrHistogram-2.2.2.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.locationtech.spatial4j/spatial4j/0.7/faa8ba85d503da4ab872d17ba8c00da0098ab2f2/spatial4j-0.7.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.locationtech.jts/jts-core/1.15.0/705981b7e25d05a76a3654e597dab6ba423eb79e/jts-core-1.15.0.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.logging.log4j/log4j-api/2.21.0/760192f2b69eacf4a4afc78e5a1d7a8de054fcbd/log4j-api-2.21.0.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.logging.log4j/log4j-jul/2.21.0/f0da61113f4a47654677e6a98b1e13ca7de2483d/log4j-jul-2.21.0.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.logging.log4j/log4j-core/2.21.0/122e1a9e0603cc9eae07b0846a6ff01f2454bc49/log4j-core-2.21.0.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/net.java.dev.jna/jna/5.13.0/1200e7ebeedbe0d10062093f32925a912020e747/jna-5.13.0.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/com.jcraft/jzlib/1.1.3/c01428efa717624f7aabf4df319939dda9646b2d/jzlib-1.1.3.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/io.projectreactor/reactor-core/3.5.20/1fc0f91e2b93778a974339d2c24363d7f34f90b4/reactor-core-3.5.20.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.reactivestreams/reactive-streams/1.0.4/3864a1320d97d7b045f729a326e1e077661f31b7/reactive-streams-1.0.4.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/com.google.protobuf/protobuf-java/3.25.4/43fcb86e4a411516c7fc681450f1516de0b862a2/protobuf-java-3.25.4.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/jakarta.annotation/jakarta.annotation-api/1.3.5/59eb84ee0d616332ff44aba065f3888cf002cd2d/jakarta.annotation-api-1.3.5.jar:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/plugin-classloader/out/production/classes:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.roaringbitmap/RoaringBitmap/1.2.1/828eb489b5e8c8762f2471010e9c7f20c7de596d/RoaringBitmap-1.2.1.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/com.github.luben/zstd-jni/1.5.5-5/74ffdc5f140080adacf5278287aadd950179f848/zstd-jni-1.5.5-5.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/com.fasterxml.jackson.core/jackson-core/2.17.2/969a35cb35c86512acbadcdbbbfb044c877db814/jackson-core-2.17.2.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.yaml/snakeyaml/2.1/c79f47315517560b5bd6a62376ee385e48105437/snakeyaml-2.1.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/com.fasterxml.jackson.dataformat/jackson-dataformat-smile/2.17.2/20e956b9b6f67138edd39fab7a506ded19638bcb/jackson-dataformat-smile-2.17.2.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/com.fasterxml.jackson.dataformat/jackson-dataformat-yaml/2.17.2/78d2c73dbec62044d7cf3b544b2e0d24a1a093b0/jackson-dataformat-yaml-2.17.2.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/com.fasterxml.jackson.dataformat/jackson-dataformat-cbor/2.17.2/57fa7c1b5104bbc4599278d13933a937ee058e68/jackson-dataformat-cbor-2.17.2.jar:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/test/telemetry/out/production/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/libs/nio/out/production/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/client/sniffer/out/production/classes:/Users/bytedance/Downloads/work_dir/opensearch_github/OpenSearch_1_for_pr/client/rest/out/production/classes:/Users/bytedance/.gradle/caches/modules-2/files-2.1/com.carrotsearch.randomizedtesting/randomizedtesting-runner/2.7.1/e917f4983144c3b969eb7d3648338ecde5e3ba89/randomizedtesting-runner-2.7.1.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/junit/junit/4.13.2/8ac9e16d933b6fb43bc7f576336b8f4d7eb5ba12/junit-4.13.2.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.hamcrest/hamcrest/2.1/9420ba32c29217b54eebd26ff7f9234d31c3fbb2/hamcrest-2.1.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-test-framework/9.12.0-snapshot-847316d/139a9dbe7b57bdae76618b2c7d2330a7c5b30423/lucene-test-framework-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.lucene/lucene-codecs/9.12.0-snapshot-847316d/dc8e69725fdec4959d996f76a3a2cc770946810/lucene-codecs-9.12.0-snapshot-847316d.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/commons-logging/commons-logging/1.2/4bfc12adfe4842bf07b657f0369c4cb522955686/commons-logging-1.2.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/commons-codec/commons-codec/1.16.1/47bd4d333fba53406f6c6c51884ddbca435c8862/commons-codec-1.16.1.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.mockito/mockito-core/5.12.0/22f8bbaf478e6789164787fa411a3b5ed986e110/mockito-core-5.12.0.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/net.bytebuddy/byte-buddy/1.14.9/b69e7fff6c473d3ed2b489cdfd673a091fd94226/byte-buddy-1.14.9.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.objenesis/objenesis/3.2/7fadf57620c8b8abdf7519533e5527367cb51f09/objenesis-3.2.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/net.sf.jopt-simple/jopt-simple/5.0.4/4fdac2fbe92dfad86aa6e9301736f6b4342a3f5c/jopt-simple-5.0.4.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.httpcomponents.client5/httpclient5/5.3.1/56b53c8f4bcdaada801d311cf2ff8a24d6d96883/httpclient5-5.3.1.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.httpcomponents.core5/httpcore5/5.2.5/dab1e18842971a45ca8942491ce005ab86a028d7/httpcore5-5.2.5.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.httpcomponents.core5/httpcore5-h2/5.2.5/9425df4d1365cee86a8e031a036bdca4343da4b/httpcore5-h2-5.2.5.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.apache.httpcomponents.core5/httpcore5-reactive/5.2.5/f68949965075b957c12b4c1ef89fd4bab2a0fdb1/httpcore5-reactive-5.2.5.jar:/Users/bytedance/.gradle/caches/modules-2/files-2.1/org.slf4j/slf4j-api/1.7.36/6c62681a2f655b49963a5983b8b0950a6120ae14/slf4j-api-1.7.36.jar com.intellij.rt.junit.JUnitStarter -ideVersion5 -junit4 org.opensearch.cluster.SpecificClusterManagerNodesIT,testElectOnlyBetweenClusterManagerNodes
[2024-09-20T02:16:05,634][INFO ][o.o.t.OpenSearchTestClusterRule] [testElectOnlyBetweenClusterManagerNodes] [SpecificClusterManagerNodesIT#testElectOnlyBetweenClusterManagerNodes]: setting up test
[2024-09-20T02:16:05,720][INFO ][o.o.t.InternalTestCluster] [testElectOnlyBetweenClusterManagerNodes] Setup InternalTestCluster [TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster] with seed [F5269DE2B5C86FE1] using [0] dedicated cluster-managers, [0] (data) nodes and [0] coord only nodes (min_cluster_manager_nodes are [manual])
[2024-09-20T02:16:06,101][INFO ][o.o.t.OpenSearchTestClusterRule] [testElectOnlyBetweenClusterManagerNodes] [SpecificClusterManagerNodesIT#testElectOnlyBetweenClusterManagerNodes]: all set up test
[2024-09-20T02:16:06,103][INFO ][o.o.c.SpecificClusterManagerNodesIT] [testElectOnlyBetweenClusterManagerNodes] before test
[2024-09-20T02:16:06,105][INFO ][o.o.c.SpecificClusterManagerNodesIT] [testElectOnlyBetweenClusterManagerNodes] --> start data node / non cluster-manager node
[2024-09-20T02:16:06,334][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] version[3.0.0], pid[36674], build[unknown/unknown/unknown], OS[Mac OS X/10.16/x86_64], JVM[Oracle Corporation/Java HotSpot(TM) 64-Bit Server VM/15.0.2/15.0.2+7-27]
[2024-09-20T02:16:06,334][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] JVM home [/Library/Java/JavaVirtualMachines/jdk-15.0.2.jdk/Contents/Home]
[2024-09-20T02:16:06,345][DEPRECATION][o.o.d.n.Node             ] [testElectOnlyBetweenClusterManagerNodes] no-jdk distributions that do not bundle a JDK are deprecated and will be removed in a future release
[2024-09-20T02:16:06,345][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] JVM arguments [-ea, -Djava.locale.providers=SPI,CLDR, -Didea.test.cyclic.buffer.size=1048576, -javaagent:/Applications/IntelliJ IDEA 4.app/Contents/lib/idea_rt.jar=60199:/Applications/IntelliJ IDEA 4.app/Contents/bin, -Dfile.encoding=UTF-8]
[2024-09-20T02:16:06,375][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] no modules loaded
[2024-09-20T02:16:06,376][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.cluster.service.applicationtemplates.TestSystemTemplatesRepositoryPlugin]
[2024-09-20T02:16:06,376][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.script.MockScriptService$TestPlugin]
[2024-09-20T02:16:06,376][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.MockHttpTransport$TestPlugin]
[2024-09-20T02:16:06,376][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.OpenSearchIntegTestCase$AssertActionNamePlugin]
[2024-09-20T02:16:06,376][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.OpenSearchIntegTestCase$TestSeedPlugin]
[2024-09-20T02:16:06,376][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.TestGeoShapeFieldMapperPlugin]
[2024-09-20T02:16:06,376][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.telemetry.MockTelemetryPlugin]
[2024-09-20T02:16:06,377][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.transport.nio.MockNioTransportPlugin]
[2024-09-20T02:16:06,418][INFO ][o.o.e.NodeEnvironment    ] [testElectOnlyBetweenClusterManagerNodes] using [3] data paths, mounts [[/System/Volumes/Data (/dev/disk3s1)]], net usable_space [44.3gb], net total_space [460.4gb], types [apfs]
[2024-09-20T02:16:06,418][INFO ][o.o.e.NodeEnvironment    ] [testElectOnlyBetweenClusterManagerNodes] heap size [8gb], compressed ordinary object pointers [true]
[2024-09-20T02:16:06,511][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] node name [node_t0], node ID [T0_KC6FiR6eYAto76oHz6A], cluster name [TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster], roles [data]
[2024-09-20T02:16:06,584][INFO ][o.o.e.ExtensionsManager  ] [testElectOnlyBetweenClusterManagerNodes] ExtensionsManager initialized
[2024-09-20T02:16:09,070][INFO ][o.o.d.DiscoveryModule    ] [testElectOnlyBetweenClusterManagerNodes] using discovery type [zen] and seed hosts providers [settings, file]
[2024-09-20T02:16:09,681][WARN ][o.o.g.DanglingIndicesState] [testElectOnlyBetweenClusterManagerNodes] gateway.auto_import_dangling_indices is disabled, dangling indices will not be automatically detected or imported and must be managed manually
[2024-09-20T02:16:09,959][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] initialized
[2024-09-20T02:16:09,966][INFO ][o.o.n.Node               ] [[test_TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster[T#1]]] starting ...
[2024-09-20T02:16:10,039][INFO ][o.o.t.TransportService   ] [[test_TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster[T#1]]] publish_address {127.0.0.1:60213}, bound_addresses {[::1]:60212}, {127.0.0.1:60213}
[2024-09-20T02:16:11,587][WARN ][o.o.n.Node               ] [node_t0] timed out while waiting for initial discovery state - timeout: 1s
[2024-09-20T02:16:11,599][INFO ][o.o.n.Node               ] [[test_TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster[T#1]]] started
[2024-09-20T02:16:11,752][INFO ][o.o.c.SpecificClusterManagerNodesIT] [testElectOnlyBetweenClusterManagerNodes] --> start cluster-manager node (1)
[2024-09-20T02:16:11,805][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] version[3.0.0], pid[36674], build[unknown/unknown/unknown], OS[Mac OS X/10.16/x86_64], JVM[Oracle Corporation/Java HotSpot(TM) 64-Bit Server VM/15.0.2/15.0.2+7-27]
[2024-09-20T02:16:11,806][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] JVM home [/Library/Java/JavaVirtualMachines/jdk-15.0.2.jdk/Contents/Home]
[2024-09-20T02:16:11,806][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] JVM arguments [-ea, -Djava.locale.providers=SPI,CLDR, -Didea.test.cyclic.buffer.size=1048576, -javaagent:/Applications/IntelliJ IDEA 4.app/Contents/lib/idea_rt.jar=60199:/Applications/IntelliJ IDEA 4.app/Contents/bin, -Dfile.encoding=UTF-8]
[2024-09-20T02:16:11,809][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] no modules loaded
[2024-09-20T02:16:11,810][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.cluster.service.applicationtemplates.TestSystemTemplatesRepositoryPlugin]
[2024-09-20T02:16:11,810][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.script.MockScriptService$TestPlugin]
[2024-09-20T02:16:11,811][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.MockHttpTransport$TestPlugin]
[2024-09-20T02:16:11,811][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.OpenSearchIntegTestCase$AssertActionNamePlugin]
[2024-09-20T02:16:11,811][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.OpenSearchIntegTestCase$TestSeedPlugin]
[2024-09-20T02:16:11,812][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.TestGeoShapeFieldMapperPlugin]
[2024-09-20T02:16:11,812][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.telemetry.MockTelemetryPlugin]
[2024-09-20T02:16:11,812][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.transport.nio.MockNioTransportPlugin]
[2024-09-20T02:16:11,824][INFO ][o.o.e.NodeEnvironment    ] [testElectOnlyBetweenClusterManagerNodes] using [3] data paths, mounts [[/System/Volumes/Data (/dev/disk3s1)]], net usable_space [44.3gb], net total_space [460.4gb], types [apfs]
[2024-09-20T02:16:11,824][INFO ][o.o.e.NodeEnvironment    ] [testElectOnlyBetweenClusterManagerNodes] heap size [8gb], compressed ordinary object pointers [true]
[2024-09-20T02:16:11,838][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] node name [node_t1], node ID [sXk90qUcRTGvEaeMZc6ZlQ], cluster name [TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster], roles [cluster_manager]
[2024-09-20T02:16:11,844][INFO ][o.o.e.ExtensionsManager  ] [testElectOnlyBetweenClusterManagerNodes] ExtensionsManager initialized
[2024-09-20T02:16:11,917][INFO ][o.o.d.DiscoveryModule    ] [testElectOnlyBetweenClusterManagerNodes] using discovery type [zen] and seed hosts providers [settings, file]
[2024-09-20T02:16:11,967][WARN ][o.o.g.DanglingIndicesState] [testElectOnlyBetweenClusterManagerNodes] gateway.auto_import_dangling_indices is disabled, dangling indices will not be automatically detected or imported and must be managed manually
[2024-09-20T02:16:11,988][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] initialized
[2024-09-20T02:16:11,991][INFO ][o.o.n.Node               ] [[test_TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster[T#2]]] starting ...
[2024-09-20T02:16:12,000][INFO ][o.o.t.TransportService   ] [[test_TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster[T#2]]] publish_address {127.0.0.1:60215}, bound_addresses {[::1]:60214}, {127.0.0.1:60215}
[2024-09-20T02:16:12,237][INFO ][o.o.c.c.Coordinator      ] [[test_TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster[T#2]]] setting initial configuration to VotingConfiguration{sXk90qUcRTGvEaeMZc6ZlQ}
[2024-09-20T02:16:12,696][INFO ][o.o.c.s.MasterService    ] [node_t1] Tasks batched with key: org.opensearch.cluster.coordination.JoinHelper and count: 3, term: 1, version: 1, delta: cluster-manager node changed {previous [], current [{node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true}]}
[2024-09-20T02:16:12,798][INFO ][o.o.c.c.CoordinationState] [node_t1] cluster UUID set to [RNGbqX02Q5efb-yRAh-5Fw]
[2024-09-20T02:16:12,891][INFO ][o.o.c.s.ClusterApplierService] [node_t1] cluster-manager node changed {previous [], current [{node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true}]}, term: 1, version: 1, reason: Publication{term=1, version=1}
[2024-09-20T02:16:12,913][INFO ][o.o.n.Node               ] [[test_TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster[T#2]]] started
[2024-09-20T02:16:12,914][INFO ][o.o.c.SpecificClusterManagerNodesIT] [testElectOnlyBetweenClusterManagerNodes] --> cluster-manager node, clusterManagerNodeName: node_t1
[2024-09-20T02:16:12,940][INFO ][o.o.d.PeerFinder         ] [node_t1] setting findPeersInterval to [1s] as node commission status = [true] for local node [{node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true}]
[2024-09-20T02:16:12,946][INFO ][o.o.c.s.MasterService    ] [node_t1] Tasks batched with key: org.opensearch.cluster.coordination.JoinHelper and count: 1, term: 1, version: 2, delta: added {{node_t0}{T0_KC6FiR6eYAto76oHz6A}{GQqlQ2IERYC19eNuB_RvHA}{127.0.0.1}{127.0.0.1:60213}{d}{shard_indexing_pressure_enabled=true}}
[2024-09-20T02:16:12,989][INFO ][o.o.c.s.ClusterApplierService] [node_t0] cluster-manager node changed {previous [], current [{node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true}]}, added {{node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true}}, term: 1, version: 2, reason: ApplyCommitRequest{term=1, version=2, sourceNode={node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}}
[2024-09-20T02:16:12,999][INFO ][o.o.c.s.ClusterApplierService] [node_t1] added {{node_t0}{T0_KC6FiR6eYAto76oHz6A}{GQqlQ2IERYC19eNuB_RvHA}{127.0.0.1}{127.0.0.1:60213}{d}{shard_indexing_pressure_enabled=true}}, term: 1, version: 2, reason: Publication{term=1, version=2}
[2024-09-20T02:16:13,001][INFO ][o.o.d.PeerFinder         ] [node_t0] setting findPeersInterval to [1s] as node commission status = [true] for local node [{node_t0}{T0_KC6FiR6eYAto76oHz6A}{GQqlQ2IERYC19eNuB_RvHA}{127.0.0.1}{127.0.0.1:60213}{d}{shard_indexing_pressure_enabled=true}]
[2024-09-20T02:16:13,008][WARN ][o.o.c.r.a.AllocationService] [node_t1] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
[2024-09-20T02:16:13,015][INFO ][o.o.c.SpecificClusterManagerNodesIT] [testElectOnlyBetweenClusterManagerNodes] --> start cluster-manager node (2)
[2024-09-20T02:16:13,022][WARN ][o.o.c.r.a.AllocationService] [node_t1] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
[2024-09-20T02:16:13,043][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] version[3.0.0], pid[36674], build[unknown/unknown/unknown], OS[Mac OS X/10.16/x86_64], JVM[Oracle Corporation/Java HotSpot(TM) 64-Bit Server VM/15.0.2/15.0.2+7-27]
[2024-09-20T02:16:13,044][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] JVM home [/Library/Java/JavaVirtualMachines/jdk-15.0.2.jdk/Contents/Home]
[2024-09-20T02:16:13,044][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] JVM arguments [-ea, -Djava.locale.providers=SPI,CLDR, -Didea.test.cyclic.buffer.size=1048576, -javaagent:/Applications/IntelliJ IDEA 4.app/Contents/lib/idea_rt.jar=60199:/Applications/IntelliJ IDEA 4.app/Contents/bin, -Dfile.encoding=UTF-8]
[2024-09-20T02:16:13,050][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] no modules loaded
[2024-09-20T02:16:13,062][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.cluster.service.applicationtemplates.TestSystemTemplatesRepositoryPlugin]
[2024-09-20T02:16:13,064][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.script.MockScriptService$TestPlugin]
[2024-09-20T02:16:13,064][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.MockHttpTransport$TestPlugin]
[2024-09-20T02:16:13,064][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.OpenSearchIntegTestCase$AssertActionNamePlugin]
[2024-09-20T02:16:13,064][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.OpenSearchIntegTestCase$TestSeedPlugin]
[2024-09-20T02:16:13,064][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.TestGeoShapeFieldMapperPlugin]
[2024-09-20T02:16:13,064][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.test.telemetry.MockTelemetryPlugin]
[2024-09-20T02:16:13,064][INFO ][o.o.p.PluginsService     ] [testElectOnlyBetweenClusterManagerNodes] loaded plugin [org.opensearch.transport.nio.MockNioTransportPlugin]
[2024-09-20T02:16:13,079][INFO ][o.o.g.GatewayService     ] [node_t1] recovered [0] indices into cluster_state
[2024-09-20T02:16:13,083][INFO ][o.o.e.NodeEnvironment    ] [testElectOnlyBetweenClusterManagerNodes] using [3] data paths, mounts [[/System/Volumes/Data (/dev/disk3s1)]], net usable_space [44.3gb], net total_space [460.4gb], types [apfs]
[2024-09-20T02:16:13,083][INFO ][o.o.e.NodeEnvironment    ] [testElectOnlyBetweenClusterManagerNodes] heap size [8gb], compressed ordinary object pointers [true]
[2024-09-20T02:16:13,094][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] node name [node_t2], node ID [3heLH5oUQhmvnAlnC5bN5Q], cluster name [TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster], roles [cluster_manager]
[2024-09-20T02:16:13,100][INFO ][o.o.e.ExtensionsManager  ] [testElectOnlyBetweenClusterManagerNodes] ExtensionsManager initialized
[2024-09-20T02:16:13,150][INFO ][o.o.d.DiscoveryModule    ] [testElectOnlyBetweenClusterManagerNodes] using discovery type [zen] and seed hosts providers [settings, file]
[2024-09-20T02:16:13,205][WARN ][o.o.g.DanglingIndicesState] [testElectOnlyBetweenClusterManagerNodes] gateway.auto_import_dangling_indices is disabled, dangling indices will not be automatically detected or imported and must be managed manually
[2024-09-20T02:16:13,225][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] initialized
[2024-09-20T02:16:13,229][INFO ][o.o.n.Node               ] [[test_TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster[T#3]]] starting ...
[2024-09-20T02:16:13,238][INFO ][o.o.t.TransportService   ] [[test_TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster[T#3]]] publish_address {127.0.0.1:60225}, bound_addresses {[::1]:60224}, {127.0.0.1:60225}
[2024-09-20T02:16:13,406][INFO ][o.o.c.s.MasterService    ] [node_t1] Tasks batched with key: org.opensearch.cluster.coordination.JoinHelper and count: 1, term: 1, version: 4, delta: added {{node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}{shard_indexing_pressure_enabled=true}}
[2024-09-20T02:16:13,439][INFO ][o.o.c.s.ClusterApplierService] [node_t0] added {{node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}{shard_indexing_pressure_enabled=true}}, term: 1, version: 4, reason: ApplyCommitRequest{term=1, version=4, sourceNode={node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}}
[2024-09-20T02:16:13,485][INFO ][o.o.c.s.ClusterApplierService] [node_t2] cluster-manager node changed {previous [], current [{node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true}]}, added {{node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true},{node_t0}{T0_KC6FiR6eYAto76oHz6A}{GQqlQ2IERYC19eNuB_RvHA}{127.0.0.1}{127.0.0.1:60213}{d}{shard_indexing_pressure_enabled=true}}, term: 1, version: 4, reason: ApplyCommitRequest{term=1, version=4, sourceNode={node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}}
[2024-09-20T02:16:13,503][INFO ][o.o.n.Node               ] [[test_TEST-TEST_WORKER_VM=[--not-gradle--]-CLUSTER_SEED=[-781763888264220703]-HASH=[EF6182365140]-cluster[T#3]]] started
[2024-09-20T02:16:13,505][INFO ][o.o.c.SpecificClusterManagerNodesIT] [testElectOnlyBetweenClusterManagerNodes] --> cluster-manager node, nextClusterManagerEligableNodeName: node_t2
[2024-09-20T02:16:13,506][INFO ][o.o.c.s.ClusterApplierService] [node_t1] added {{node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}{shard_indexing_pressure_enabled=true}}, term: 1, version: 4, reason: Publication{term=1, version=4}
[2024-09-20T02:16:13,509][INFO ][o.o.d.PeerFinder         ] [node_t2] setting findPeersInterval to [1s] as node commission status = [true] for local node [{node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}{shard_indexing_pressure_enabled=true}]
[2024-09-20T02:16:13,509][WARN ][o.o.c.r.a.AllocationService] [node_t1] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
[2024-09-20T02:16:13,513][INFO ][o.o.c.SpecificClusterManagerNodesIT] [testElectOnlyBetweenClusterManagerNodes] --> closing cluster-manager node (1)  : node_t1
[2024-09-20T02:16:13,862][INFO ][o.o.c.c.Coordinator      ] [node_t1] abdicating to {node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}{shard_indexing_pressure_enabled=true} with term 2
[2024-09-20T02:16:13,871][INFO ][o.o.c.s.ClusterApplierService] [node_t0] cluster-manager node changed {previous [{node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true}], current []}, term: 1, version: 6, reason: becoming candidate: joinLeaderInTerm
[2024-09-20T02:16:13,882][INFO ][o.o.c.s.ClusterApplierService] [node_t1] cluster-manager node changed {previous [{node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true}], current []}, term: 1, version: 6, reason: becoming candidate: after abdicating to {node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}{shard_indexing_pressure_enabled=true}
[2024-09-20T02:16:13,895][INFO ][o.o.c.s.ClusterApplierService] [node_t2] cluster-manager node changed {previous [{node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true}], current []}, term: 1, version: 6, reason: becoming candidate: joinLeaderInTerm
[2024-09-20T02:16:13,902][INFO ][o.o.c.SpecificClusterManagerNodesIT] [testElectOnlyBetweenClusterManagerNodes] after test
[2024-09-20T02:16:13,907][INFO ][o.o.c.s.MasterService    ] [node_t2] Tasks batched with key: org.opensearch.cluster.coordination.JoinHelper and count: 4, term: 2, version: 7, delta: cluster-manager node changed {previous [], current [{node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}{shard_indexing_pressure_enabled=true}]}
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
[2024-09-20T02:16:13,964][INFO ][o.o.t.OpenSearchTestClusterRule] [testElectOnlyBetweenClusterManagerNodes] [SpecificClusterManagerNodesIT#testElectOnlyBetweenClusterManagerNodes]: cleaning up after test
[2024-09-20T02:16:14,010][INFO ][o.o.c.s.ClusterApplierService] [node_t0] cluster-manager node changed {previous [], current [{node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}{shard_indexing_pressure_enabled=true}]}, term: 2, version: 7, reason: ApplyCommitRequest{term=2, version=7, sourceNode={node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}}
[2024-09-20T02:16:14,011][INFO ][o.o.c.s.ClusterApplierService] [node_t1] cluster-manager node changed {previous [], current [{node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}{shard_indexing_pressure_enabled=true}]}, term: 2, version: 7, reason: ApplyCommitRequest{term=2, version=7, sourceNode={node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}}
[2024-09-20T02:16:14,015][INFO ][o.o.c.s.ClusterApplierService] [node_t2] cluster-manager node changed {previous [], current [{node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}{shard_indexing_pressure_enabled=true}]}, term: 2, version: 7, reason: Publication{term=2, version=7}
[2024-09-20T02:16:14,030][INFO ][o.o.d.PeerFinder         ] [node_t2] setting findPeersInterval to [1s] as node commission status = [true] for local node [{node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}{shard_indexing_pressure_enabled=true}]
[2024-09-20T02:16:14,031][INFO ][o.o.d.PeerFinder         ] [node_t0] setting findPeersInterval to [1s] as node commission status = [true] for local node [{node_t0}{T0_KC6FiR6eYAto76oHz6A}{GQqlQ2IERYC19eNuB_RvHA}{127.0.0.1}{127.0.0.1:60213}{d}{shard_indexing_pressure_enabled=true}]
[2024-09-20T02:16:14,061][WARN ][o.o.c.r.a.AllocationService] [node_t2] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
[2024-09-20T02:16:14,061][INFO ][o.o.d.PeerFinder         ] [node_t0] setting findPeersInterval to [1s] as node commission status = [true] for local node [{node_t0}{T0_KC6FiR6eYAto76oHz6A}{GQqlQ2IERYC19eNuB_RvHA}{127.0.0.1}{127.0.0.1:60213}{d}{shard_indexing_pressure_enabled=true}]
[2024-09-20T02:16:14,061][INFO ][o.o.d.PeerFinder         ] [node_t1] setting findPeersInterval to [1s] as node commission status = [true] for local node [{node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true}]
[2024-09-20T02:16:14,062][INFO ][o.o.d.PeerFinder         ] [node_t1] setting findPeersInterval to [1s] as node commission status = [true] for local node [{node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true}]
[2024-09-20T02:16:14,124][WARN ][o.o.c.r.a.AllocationService] [node_t2] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
[2024-09-20T02:16:14,161][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] stopping ...
[2024-09-20T02:16:14,178][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] stopped
[2024-09-20T02:16:14,178][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] closing ...
[2024-09-20T02:16:14,167][INFO ][o.o.c.c.Coordinator      ] [node_t0] cluster-manager node [{node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}{shard_indexing_pressure_enabled=true}] failed, restarting discovery
org.opensearch.transport.NodeDisconnectedException: [node_t2][127.0.0.1:60225][disconnected] disconnected
[2024-09-20T02:16:14,199][INFO ][o.o.c.c.FollowersChecker ] [node_t2] FollowerChecker{discoveryNode={node_t0}{T0_KC6FiR6eYAto76oHz6A}{GQqlQ2IERYC19eNuB_RvHA}{127.0.0.1}{127.0.0.1:60213}{d}{shard_indexing_pressure_enabled=true}, failureCountSinceLastSuccess=0, [cluster.fault_detection.follower_check.retry_count]=3} disconnected
[2024-09-20T02:16:14,203][INFO ][o.o.c.c.FollowersChecker ] [node_t2] FollowerChecker{discoveryNode={node_t0}{T0_KC6FiR6eYAto76oHz6A}{GQqlQ2IERYC19eNuB_RvHA}{127.0.0.1}{127.0.0.1:60213}{d}{shard_indexing_pressure_enabled=true}, failureCountSinceLastSuccess=0, [cluster.fault_detection.follower_check.retry_count]=3} marking node as faulty
[2024-09-20T02:16:14,208][WARN ][o.o.c.r.a.AllocationService] [node_t2] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
[2024-09-20T02:16:14,209][INFO ][o.o.c.s.MasterService    ] [node_t2] Tasks batched with key: org.opensearch.cluster.coordination.NodeRemovalClusterStateTaskExecutor@26ce1d20 and count: 1, term: 2, version: 10, delta: removed {{node_t0}{T0_KC6FiR6eYAto76oHz6A}{GQqlQ2IERYC19eNuB_RvHA}{127.0.0.1}{127.0.0.1:60213}{d}{shard_indexing_pressure_enabled=true}}
[2024-09-20T02:16:14,212][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] closed
[2024-09-20T02:16:14,214][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] stopping ...
[2024-09-20T02:16:14,218][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] stopped
[2024-09-20T02:16:14,219][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] closing ...
[2024-09-20T02:16:14,220][INFO ][o.o.c.c.FollowersChecker ] [node_t2] FollowerChecker{discoveryNode={node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true}, failureCountSinceLastSuccess=0, [cluster.fault_detection.follower_check.retry_count]=3} disconnected
[2024-09-20T02:16:14,220][INFO ][o.o.c.c.FollowersChecker ] [node_t2] FollowerChecker{discoveryNode={node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true}, failureCountSinceLastSuccess=0, [cluster.fault_detection.follower_check.retry_count]=3} marking node as faulty
[2024-09-20T02:16:14,240][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] closed
[2024-09-20T02:16:14,239][INFO ][o.o.c.c.Coordinator      ] [node_t1] cluster-manager node [{node_t2}{3heLH5oUQhmvnAlnC5bN5Q}{yaIQnBHjRWexujCNM5hjdA}{127.0.0.1}{127.0.0.1:60225}{m}{shard_indexing_pressure_enabled=true}] failed, restarting discovery
org.opensearch.transport.NodeDisconnectedException: [node_t2][127.0.0.1:60225][disconnected] disconnected
[2024-09-20T02:16:14,242][INFO ][o.o.c.s.ClusterApplierService] [node_t2] removed {{node_t0}{T0_KC6FiR6eYAto76oHz6A}{GQqlQ2IERYC19eNuB_RvHA}{127.0.0.1}{127.0.0.1:60213}{d}{shard_indexing_pressure_enabled=true}}, term: 2, version: 10, reason: Publication{term=2, version=10}
[2024-09-20T02:16:14,246][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] stopping ...
[2024-09-20T02:16:14,254][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] stopped
[2024-09-20T02:16:14,255][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] closing ...
[2024-09-20T02:16:14,263][INFO ][o.o.n.Node               ] [testElectOnlyBetweenClusterManagerNodes] closed
[2024-09-20T02:16:14,249][WARN ][o.o.c.NodeConnectionsService] [node_t2] failed to connect to {node_t1}{sXk90qUcRTGvEaeMZc6ZlQ}{q24yhVi_Qy6cSMLRPCI68g}{127.0.0.1}{127.0.0.1:60215}{m}{shard_indexing_pressure_enabled=true} (tried [1] times)
org.opensearch.transport.ConnectTransportException: [node_t1][127.0.0.1:60215] connect_exception
    at org.opensearch.transport.TcpTransport$ChannelsConnectedListener.onFailure(TcpTransport.java:1106) ~[classes/:?]
    at org.opensearch.core.action.ActionListener.lambda$toBiConsumer$2(ActionListener.java:217) ~[classes/:?]
    at org.opensearch.common.concurrent.CompletableContext.lambda$addListener$0(CompletableContext.java:57) ~[classes/:?]
    at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859) ~[?:?]
    at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837) ~[?:?]
    at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) ~[?:?]
    at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2152) ~[?:?]
    at org.opensearch.common.concurrent.CompletableContext.completeExceptionally(CompletableContext.java:72) ~[classes/:?]
    at org.opensearch.nio.SocketChannelContext.connect(SocketChannelContext.java:160) ~[classes/:?]
    at org.opensearch.nio.EventHandler.handleConnect(EventHandler.java:130) ~[classes/:?]
    at org.opensearch.transport.nio.TestEventHandler.handleConnect(TestEventHandler.java:139) ~[classes/:?]
    at org.opensearch.nio.NioSelector.attemptConnect(NioSelector.java:446) ~[classes/:?]
    at org.opensearch.nio.NioSelector.registerChannel(NioSelector.java:469) ~[classes/:?]
    at org.opensearch.nio.NioSelector.setUpNewChannels(NioSelector.java:458) ~[classes/:?]
    at org.opensearch.nio.NioSelector.preSelect(NioSelector.java:279) ~[classes/:?]
    at org.opensearch.nio.NioSelector.singleLoop(NioSelector.java:172) ~[classes/:?]
    at org.opensearch.nio.NioSelector.runLoop(NioSelector.java:148) ~[classes/:?]
    at java.base/java.lang.Thread.run(Thread.java:832) [?:?]
Caused by: java.net.ConnectException: Connection refused
    at java.base/sun.nio.ch.Net.pollConnect(Native Method) ~[?:?]
    at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:660) ~[?:?]
    at java.base/sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:875) ~[?:?]
    at org.opensearch.nio.SocketChannelContext.connect(SocketChannelContext.java:157) ~[classes/:?]
    ... 9 more
[2024-09-20T02:16:14,268][INFO ][o.o.t.OpenSearchTestClusterRule] [testElectOnlyBetweenClusterManagerNodes] [SpecificClusterManagerNodesIT#testElectOnlyBetweenClusterManagerNodes]: cleaned up after test
REPRODUCE WITH: ./gradlew 'null' --tests "org.opensearch.cluster.SpecificClusterManagerNodesIT.testElectOnlyBetweenClusterManagerNodes" -Dtests.seed=7205B743D1F3E4A0 -Dtests.locale=en-PK -Dtests.timezone=America/Tegucigalpa -Druntime.java=15

java.lang.NullPointerException: Cannot invoke "org.opensearch.cluster.node.DiscoveryNode.getName()" because the return value of "org.opensearch.cluster.node.DiscoveryNodes.getClusterManagerNode()" is null

    at __randomizedtesting.SeedInfo.seed([7205B743D1F3E4A0:7568B5028CA35F88]:0)
    at org.opensearch.cluster.SpecificClusterManagerNodesIT.lambda$testElectOnlyBetweenClusterManagerNodes$0(SpecificClusterManagerNodesIT.java:259)
    at org.opensearch.test.OpenSearchTestCase.assertBusy(OpenSearchTestCase.java:1124)
    at org.opensearch.test.OpenSearchTestCase.assertBusy(OpenSearchTestCase.java:1109)
    at org.opensearch.cluster.SpecificClusterManagerNodesIT.testElectOnlyBetweenClusterManagerNodes(SpecificClusterManagerNodesIT.java:248)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:564)
    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 org.opensearch.test.OpenSearchTestClusterRule$1.evaluate(OpenSearchTestClusterRule.java:369)
    at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
    at org.junit.rules.RunRules.evaluate(RunRules.java:20)
    at org.apache.lucene.tests.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:48)
    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 org.junit.rules.RunRules.evaluate(RunRules.java:20)
    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.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 org.junit.rules.RunRules.evaluate(RunRules.java:20)
    at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
    at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
    at java.base/java.lang.Thread.run(Thread.java:832)

Expected behavior

Test should always pass

Additional Details

Plugins Please list all plugins currently enabled.

Screenshots If applicable, add screenshots to help explain your problem.

Host/Environment (please complete the following information):

Additional context Add any other context about the problem here.

kkewwei commented 1 month ago

More details:

  1. When the node_t1 is excluded from the vote config, and the cluster starts a new leader election, but the the node node_t2 hasn't been elected as the new leader.

  2. At the moment, we send request to get the ClusterManager, we first get ClusterManager name, and leads to the NullPointerException.

internalCluster().nonClusterManagerClient()-> ......->getClusterManagerName()

https://github.com/opensearch-project/OpenSearch/blob/f0ea056a93383c4ca7cac361fdf8c73e8afc3941/test/framework/src/main/java/org/opensearch/test/InternalTestCluster.java#L2171

[2024-09-20T14:09:20,164][DEBUG][o.o.t.TransportService   ] [testElectOnlyBetweenClusterManagerNodes] Action: internal:monitor/term
[2024-09-20T14:09:20,167][DEBUG][o.o.c.s.ClusterApplierService] [node_t0] processing [becoming candidate: joinLeaderInTerm]: execute
[2024-09-20T14:09:20,167][DEBUG][o.o.c.s.ClusterApplierService] [node_t0] cluster state updated, version [6], source [becoming candidate: joinLeaderInTerm]
[2024-09-20T14:09:20,168][INFO ][o.o.c.s.ClusterApplierService] [node_t0] cluster-manager node changed {previous [{node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}], current []}, term: 1, version: 6, reason: becoming candidate: joinLeaderInTerm
[2024-09-20T14:09:20,168][DEBUG][o.o.c.c.JoinHelper       ] [node_t0] attempting to join {node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true} with JoinRequest{sourceNode={node_t0}{iTIfjfecSyKNwNqmlwoS9A}{HEvdv2ZbR1W6osMrJfOlSQ}{127.0.0.1}{127.0.0.1:61664}{d}{shard_indexing_pressure_enabled=true}, minimumTerm=1, optionalJoin=Optional[Join{term=2, lastAcceptedTerm=1, lastAcceptedVersion=6, sourceNode={node_t0}{iTIfjfecSyKNwNqmlwoS9A}{HEvdv2ZbR1W6osMrJfOlSQ}{127.0.0.1}{127.0.0.1:61664}{d}{shard_indexing_pressure_enabled=true}, targetNode={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}}]}
[2024-09-20T14:09:20,168][DEBUG][o.o.c.s.ClusterApplierService] [node_t0] apply cluster state with version 6
[2024-09-20T14:09:20,168][DEBUG][o.o.t.TransportService   ] [node_t0] Action: internal:cluster/coordination/join
[2024-09-20T14:09:20,168][DEBUG][o.o.c.s.ClusterApplierService] [node_t0] set locally applied cluster state to version 6
[2024-09-20T14:09:20,168][DEBUG][o.o.c.s.ClusterApplierService] [node_t0] processing [becoming candidate: joinLeaderInTerm]: took [0s] done applying updated cluster state (version: 6, uuid: sCFlUbCGT4GtAN3upFZjSA)
[2024-09-20T14:09:20,169][DEBUG][o.o.c.s.ClusterApplierService] [node_t1] processing [becoming candidate: after abdicating to {node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}]: execute
[2024-09-20T14:09:20,169][DEBUG][o.o.c.s.ClusterApplierService] [node_t1] cluster state updated, version [6], source [becoming candidate: after abdicating to {node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}]
[2024-09-20T14:09:20,169][DEBUG][o.o.c.s.MasterService    ] [node_t1] took [0s] to notify listeners on successful publication of cluster state (version: 6, uuid: sCFlUbCGT4GtAN3upFZjSA) for [Tasks batched with key: org.opensearch.cluster.coordination.Coordinator and count: 1]
[2024-09-20T14:09:20,169][INFO ][o.o.c.s.ClusterApplierService] [node_t1] cluster-manager node changed {previous [{node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}], current []}, term: 1, version: 6, reason: becoming candidate: after abdicating to {node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}
[2024-09-20T14:09:20,169][DEBUG][o.o.c.c.Coordinator      ] [node_t1] joinLeaderInTerm: for [{node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}] with term 2
[2024-09-20T14:09:20,169][DEBUG][o.o.c.s.MasterService    ] [node_t1] executing cluster state update for [Tasks batched with key: org.opensearch.cluster.coordination.Coordinator and count: 1]
[2024-09-20T14:09:20,169][DEBUG][o.o.c.s.ClusterApplierService] [node_t1] apply cluster state with version 6
[2024-09-20T14:09:20,169][DEBUG][o.o.c.c.CoordinationState] [node_t1] handleStartJoin: leaving term [1] due to StartJoinRequest{term=2,node={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}}
[2024-09-20T14:09:20,169][DEBUG][o.o.c.c.CoordinationState] [node_t1] handleStartJoin: discarding VoteCollection{votes=[rSwcqPy5TuC7WxPExXRFpQ, 87r6gSkrQ4uTH-eZIr698A], joins=[Join{term=1, lastAcceptedTerm=0, lastAcceptedVersion=0, sourceNode={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}, targetNode={node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}}, Join{term=1, lastAcceptedTerm=0, lastAcceptedVersion=0, sourceNode={node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}, targetNode={node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}}]}: standing down as leader
[2024-09-20T14:09:20,169][DEBUG][o.o.c.s.ClusterApplierService] [node_t1] set locally applied cluster state to version 6
[2024-09-20T14:09:20,170][DEBUG][o.o.c.c.JoinHelper       ] [node_t1] successful response to StartJoinRequest{term=2,node={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}} from {node_t0}{iTIfjfecSyKNwNqmlwoS9A}{HEvdv2ZbR1W6osMrJfOlSQ}{127.0.0.1}{127.0.0.1:61664}{d}{shard_indexing_pressure_enabled=true}
[2024-09-20T14:09:20,202][DEBUG][o.o.n.r.t.AverageCpuUsageTracker] [node_t0] Recording cpu usage: 24%
[2024-09-20T14:09:20,216][DEBUG][o.o.t.TcpTransport       ] [node_t0] opened transport connection [4] to [{127.0.0.1:61706}{vjUcsf__T_-Kuw_f_____w}{127.0.0.1}{127.0.0.1:61706}] using channels [[NioSocketChannel{localAddress=/127.0.0.1:61722, remoteAddress=127.0.0.1/127.0.0.1:61706}]]
[2024-09-20T14:09:20,200][DEBUG][o.o.c.s.MasterService    ] [node_t1] took [0s] to compute cluster state update for [Tasks batched with key: org.opensearch.cluster.coordination.Coordinator and count: 1]
[2024-09-20T14:09:20,178][DEBUG][o.o.c.s.ClusterApplierService] [node_t1] processing [becoming candidate: after abdicating to {node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}]: took [0s] done applying updated cluster state (version: 6, uuid: sCFlUbCGT4GtAN3upFZjSA)
[2024-09-20T14:09:20,203][DEBUG][o.o.n.r.t.AverageMemoryUsageTracker] [node_t0] Recording memory usage: 0%
[2024-09-20T14:09:20,193][DEBUG][o.o.d.FileBasedSeedHostsProvider] [node_t0] seed addresses: [127.0.0.1:61696, 127.0.0.1:61706]
[2024-09-20T14:09:20,201][DEBUG][o.o.c.c.Coordinator      ] [node_t2] joinLeaderInTerm: coordinator becoming CANDIDATE in term 2 (was FOLLOWER, lastKnownLeader was [Optional[{node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}]])
[2024-09-20T14:09:20,192][DEBUG][o.o.d.FileBasedSeedHostsProvider] [node_t1] seed addresses: [127.0.0.1:61706]
[2024-09-20T14:09:20,205][DEBUG][o.o.c.c.JoinHelper       ] [node_t1] attempting to join {node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true} with JoinRequest{sourceNode={node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}, minimumTerm=1, optionalJoin=Optional[Join{term=2, lastAcceptedTerm=1, lastAcceptedVersion=6, sourceNode={node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}, targetNode={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}}]}
[2024-09-20T14:09:20,219][DEBUG][o.o.c.s.MasterService    ] [node_t1] took [0s] to notify listeners on unchanged cluster state for [Tasks batched with key: org.opensearch.cluster.coordination.Coordinator and count: 1]
[2024-09-20T14:09:20,220][DEBUG][o.o.t.TransportService   ] [node_t0] Action: internal:transport/handshake
[2024-09-20T14:09:20,220][DEBUG][o.o.t.TransportService   ] [node_t1] Action: internal:cluster/coordination/join
[2024-09-20T14:09:20,220][DEBUG][o.o.t.TcpTransport       ] [node_t1] opened transport connection [3] to [{127.0.0.1:61706}{vjUcsf__T_-Kuw_f_____w}{127.0.0.1}{127.0.0.1:61706}] using channels [[NioSocketChannel{localAddress=/127.0.0.1:61720, remoteAddress=127.0.0.1/127.0.0.1:61706}]]
[2024-09-20T14:09:20,220][DEBUG][o.o.c.c.ElectionSchedulerFactory] [node_t2] scheduling scheduleNextElection{gracePeriod=0s, thisAttempt=0, maxDelayMillis=100, delayMillis=91, ElectionScheduler{attempt=1, ElectionSchedulerFactory{initialTimeout=100ms, backoffTime=100ms, maxTimeout=10s}}}
[2024-09-20T14:09:20,221][DEBUG][o.o.t.TransportService   ] [node_t1] Action: internal:transport/handshake
[2024-09-20T14:09:20,222][DEBUG][o.o.t.TcpTransport       ] [node_t0] opened transport connection [5] to [{127.0.0.1:61696}{vjUcsf__T_-Kuw_f_____w}{127.0.0.1}{127.0.0.1:61696}] using channels [[NioSocketChannel{localAddress=/127.0.0.1:61721, remoteAddress=127.0.0.1/127.0.0.1:61696}]]
[2024-09-20T14:09:20,221][DEBUG][o.o.c.c.LeaderChecker    ] [node_t2] closed
[2024-09-20T14:09:20,226][DEBUG][o.o.t.TransportService   ] [node_t0] Action: internal:transport/handshake
[2024-09-20T14:09:20,228][DEBUG][o.o.d.FileBasedSeedHostsProvider] [node_t2] seed addresses: [127.0.0.1:61696]
[2024-09-20T14:09:20,228][DEBUG][o.o.c.c.JoinHelper       ] [node_t1] successful response to StartJoinRequest{term=2,node={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}} from {node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}
[2024-09-20T14:09:20,231][DEBUG][o.o.c.s.ClusterApplierService] [node_t2] processing [becoming candidate: joinLeaderInTerm]: execute
[2024-09-20T14:09:20,231][DEBUG][o.o.c.s.ClusterApplierService] [node_t2] cluster state updated, version [6], source [becoming candidate: joinLeaderInTerm]
[2024-09-20T14:09:20,231][DEBUG][o.o.c.c.CoordinationState] [node_t2] handleJoin: added join Join{term=2, lastAcceptedTerm=1, lastAcceptedVersion=6, sourceNode={node_t0}{iTIfjfecSyKNwNqmlwoS9A}{HEvdv2ZbR1W6osMrJfOlSQ}{127.0.0.1}{127.0.0.1:61664}{d}{shard_indexing_pressure_enabled=true}, targetNode={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}} from [{node_t0}{iTIfjfecSyKNwNqmlwoS9A}{HEvdv2ZbR1W6osMrJfOlSQ}{127.0.0.1}{127.0.0.1:61664}{d}{shard_indexing_pressure_enabled=true}] for election, electionWon=false lastAcceptedTerm=1 lastAcceptedVersion=6
[2024-09-20T14:09:20,232][INFO ][o.o.c.s.ClusterApplierService] [node_t2] cluster-manager node changed {previous [{node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}], current []}, term: 1, version: 6, reason: becoming candidate: joinLeaderInTerm
[2024-09-20T14:09:20,232][DEBUG][o.o.c.s.ClusterApplierService] [node_t2] apply cluster state with version 6
[2024-09-20T14:09:20,232][DEBUG][o.o.c.s.ClusterApplierService] [node_t2] set locally applied cluster state to version 6
[2024-09-20T14:09:20,233][DEBUG][o.o.c.s.ClusterApplierService] [node_t2] processing [becoming candidate: joinLeaderInTerm]: took [0s] done applying updated cluster state (version: 6, uuid: sCFlUbCGT4GtAN3upFZjSA)
[2024-09-20T14:09:20,233][DEBUG][o.o.c.c.JoinHelper       ] [node_t2] attempting to join {node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true} with JoinRequest{sourceNode={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}, minimumTerm=1, optionalJoin=Optional[Join{term=2, lastAcceptedTerm=1, lastAcceptedVersion=6, sourceNode={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}, targetNode={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}}]}
[2024-09-20T14:09:20,235][DEBUG][o.o.t.TransportService   ] [node_t2] Action: internal:cluster/coordination/join
[2024-09-20T14:09:20,239][DEBUG][o.o.c.c.CoordinationState] [node_t2] handleJoin: added join Join{term=2, lastAcceptedTerm=1, lastAcceptedVersion=6, sourceNode={node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}, targetNode={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}} from [{node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}] for election, electionWon=false lastAcceptedTerm=1 lastAcceptedVersion=6
[2024-09-20T14:09:20,240][DEBUG][o.o.t.TcpTransport       ] [node_t0] closed transport connection [5] to [{127.0.0.1:61696}{vjUcsf__T_-Kuw_f_____w}{127.0.0.1}{127.0.0.1:61696}] with age [0ms]
[2024-09-20T14:09:20,240][DEBUG][o.o.t.TcpTransport       ] [node_t0] closed transport connection [4] to [{127.0.0.1:61706}{vjUcsf__T_-Kuw_f_____w}{127.0.0.1}{127.0.0.1:61706}] with age [0ms]
[2024-09-20T14:09:20,240][DEBUG][o.o.c.c.CoordinationState] [node_t2] handleJoin: added join Join{term=2, lastAcceptedTerm=1, lastAcceptedVersion=6, sourceNode={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}, targetNode={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}} from [{node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}] for election, electionWon=true lastAcceptedTerm=1 lastAcceptedVersion=6
[2024-09-20T14:09:20,241][DEBUG][o.o.c.c.CoordinationState] [node_t2] handleJoin: election won in term [2] with VoteCollection{votes=[rSwcqPy5TuC7WxPExXRFpQ, 87r6gSkrQ4uTH-eZIr698A], joins=[Join{term=2, lastAcceptedTerm=1, lastAcceptedVersion=6, sourceNode={node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}, targetNode={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}}, Join{term=2, lastAcceptedTerm=1, lastAcceptedVersion=6, sourceNode={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}, targetNode={node_t2}{rSwcqPy5TuC7WxPExXRFpQ}{Qh3crORDQlG2QVH4siYwNg}{127.0.0.1}{127.0.0.1:61706}{m}{shard_indexing_pressure_enabled=true}}]}
[2024-09-20T14:09:20,242][DEBUG][o.o.c.c.Coordinator      ] [node_t2] handleJoinRequest: coordinator becoming LEADER in term 2 (was CANDIDATE, lastKnownLeader was [Optional[{node_t1}{87r6gSkrQ4uTH-eZIr698A}{qhTYNnkYSmiSXYu7qZbJHg}{127.0.0.1}{127.0.0.1:61696}{m}{shard_indexing_pressure_enabled=true}]])
[2024-09-20T14:09:20,242][DEBUG][o.o.t.TransportService   ] [node_t0] Action: internal:discovery/request_peers
[2024-09-20T14:09:20,176][WARN ][o.o.t.InternalTestCluster] [testElectOnlyBetweenClusterManagerNodes] Can't fetch cluster state
java.lang.NullPointerException: Cannot invoke "org.opensearch.cluster.node.DiscoveryNode.getName()" because the return value of "org.opensearch.cluster.node.DiscoveryNodes.getClusterManagerNode()" is null
    at org.opensearch.test.InternalTestCluster.getClusterManagerName(InternalTestCluster.java:2173) [classes/:?]
    at org.opensearch.test.InternalTestCluster.getClusterManagerName(InternalTestCluster.java:2163) [classes/:?]
    at org.opensearch.test.InternalTestCluster.nonClusterManagerClient(InternalTestCluster.java:897) [classes/:?]
    at org.opensearch.cluster.SpecificClusterManagerNodesIT.lambda$testElectOnlyBetweenClusterManagerNodes$0(SpecificClusterManagerNodesIT.java:252) [classes/:?]
    at org.opensearch.test.OpenSearchTestCase.assertBusy(OpenSearchTestCase.java:1124) [classes/:?]
    at org.opensearch.test.OpenSearchTestCase.assertBusy(OpenSearchTestCase.java:1109) [classes/:?]
    at org.opensearch.cluster.SpecificClusterManagerNodesIT.testElectOnlyBetweenClusterManagerNodes(SpecificClusterManagerNodesIT.java:250) [classes/:?]
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64) ~[?:?]
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.base/java.lang.reflect.Method.invoke(Method.java:564) ~[?:?]
    at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750) [randomizedtesting-runner-2.7.1.jar:?]
    at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938) [randomizedtesting-runner-2.7.1.jar:?]
    at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974) [randomizedtesting-runner-2.7.1.jar:?]
    at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988) [randomizedtesting-runner-2.7.1.jar:?]
    at org.opensearch.test.OpenSearchTestClusterRule$1.evaluate(OpenSearchTestClusterRule.java:369) [classes/:?]
    at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.1.jar:?]
    at org.junit.rules.RunRules.evaluate(RunRules.java:20) [junit-4.13.2.jar:4.13.2]
rajiv-kv commented 1 month ago

[Triage - attendees 1 2 3] Thanks @kkewwei for filing the request. Looks like the test needs to wait until the new master is elected. Please feel free to raise a pull request.

kkewwei commented 1 month ago

[Triage - attendees 1 2 3] Thanks @kkewwei for filing the request. Looks like the test needs to wait until the new master is elected. Please feel free to raise a pull request.

@rajiv-kv, it's ok now, please have a look #16021.

dblock commented 3 weeks ago

[Catch All Triage - 1, 2, 3, 4]