Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[BUG] [Flaky Test] PredictionITTests are being flaky #3550

Closed
rithin-pullela-aws opened this issue Feb 14, 2025 · 5 comments · Fixed by #3647
Closed

[BUG] [Flaky Test] PredictionITTests are being flaky #3550

rithin-pullela-aws opened this issue Feb 14, 2025 · 5 comments · Fixed by #3647
Assignees
@rithin-pullela-aws
Labels
bug Something isn't working

Comments

@rithin-pullela-aws
Copy link
Contributor

What is the bug?
I observed this test showing flaky behavior, find the workflow here

StackTrace:

REPRODUCE WITH: gradlew ':opensearch-ml-plugin:test' --tests "org.opensearch.ml.action.prediction.PredictionITTests.testPredictionWithDataFrame_BatchRCF" -Dtests.seed=F9FEF2C7942CCFB9 -Dtests.security.manager=false -Dtests.locale=ar-AE -Dtests.timezone=America/Tijuana -Druntime.java=23
PredictionITTests > testPredictionWithDataFrame_BatchRCF FAILED
    java.util.ConcurrentModificationException
        at __randomizedtesting.SeedInfo.seed([F9FEF2C7942CCFB9:FACB8B53785882F2]:0)
        at java.base/java.util.HashMap$ValueSpliterator.forEachRemaining(HashMap.java:1793)
        at java.base/java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:807)
        at java.base/java.util.stream.ReferencePipeline$7$1FlatMap.accept(ReferencePipeline.java:294)
        at java.base/java.util.WeakHashMap$ValueSpliterator.forEachRemaining(WeakHashMap.java:1224)
        at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:570)
        at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:560)
        at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
        at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:265)
        at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:636)
        at org.apache.logging.log4j.core.LoggerContext.updateLoggers(LoggerContext.java:776)
        at org.apache.logging.log4j.core.LoggerContext.updateLoggers(LoggerContext.java:766)
        at org.opensearch.common.logging.Loggers.removeAppender(Loggers.java:176)
        at org.opensearch.test.OpenSearchTestCase.removeHeaderWarningAppender(OpenSearchTestCase.java:411)
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
        at java.base/java.lang.reflect.Method.invoke(Method.java:580)
        at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:996)
        at org.opensearch.test.OpenSearchTestClusterRule$1.evaluate(OpenSearchTestClusterRule.java:369)
        at org.junit.rules.ExpectedException$ExpectedExceptionStatement.evaluate(ExpectedException.java:258)
        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:1575)

  1> [2025-02-13T13:32:17,840][INFO ][o.o.t.OpenSearchTestClusterRule] [testPredictionWithDataFrame_BatchRCF] [PredictionITTests#testPredictionWithDataFrame_BatchRCF]: setting up test

  1> [2025-02-13T13:32:17,855][INFO ][o.o.t.InternalTestCluster] [testPredictionWithDataFrame_BatchRCF] Setup InternalTestCluster [SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster] with seed [F729707CAE6D6616] using [1] dedicated cluster-managers, [2] (data) nodes and [0] coord only nodes (min_cluster_manager_nodes are [auto-managed])
Suite: Test class org.opensearch.ml.action.prediction.PredictionITTests
  1> [2025-02-13T13:32:17,855][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] version[3.0.0-alpha1-SNAPSHOT], pid[2248], build[unknown/38e4b335f5182c0efefc0d88fee733805304f95b/2025-02-13T15:49:48.790936216Z], OS[Windows Server 2022/10.0/amd64], JVM[Azul Systems, Inc./OpenJDK 64-Bit Server VM/23.0.2/23.0.2+7]
  1> [2025-02-13T13:32:17,855][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] JVM home [C:\hostedtoolcache\windows\jdk\23.0.2\x64]
  1> [2025-02-13T13:32:17,855][DEPRECATION][o.o.d.n.Node             ] [testPredictionWithDataFrame_BatchRCF] no-jdk distributions that do not bundle a JDK are deprecated and will be removed in a future release
  1> [2025-02-13T13:32:17,855][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] JVM arguments [-Dgradle.dist.lib=C:\Users\runneradmin\.gradle\wrapper\dists\gradle-8.11.1-bin\bpt9gzteqjrbo1mjrsomdt32c\gradle-8.11.1\lib, -Dgradle.user.home=C:\Users\runneradmin\.gradle, -Dgradle.worker.jar=C:\Users\runneradmin\.gradle/caches/8.11.1/workerMain/gradle-worker.jar, -Dio.netty.noKeySetOptimization=true, -Dio.netty.noUnsafe=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Djava.awt.headless=true, -Djava.locale.providers=SPI,CLDR, -Djava.security.manager=allow, -Djna.nosys=true, -Dopensearch.scripting.update.ctx_in_params=false, -Dopensearch.search.rewrite_sort=true, -Dopensearch.transport.cname_in_publish_address=true, -Dorg.gradle.internal.worker.tmpdir=D:\a\ml-commons\ml-commons\plugin\build\tmp\test\work, -Dtests.artifact=opensearch-ml-plugin, -Dtests.gradle=true, -Dtests.logger.level=WARN, -Dtests.security.manager=false, -Dtests.seed=F9FEF2C7942CCFB9, -Dtests.task=:opensearch-ml-plugin:test, -Dtests.timeoutSuite=1800000!, -XX:+HeapDumpOnOutOfMemoryError, -esa, -javaagent:D:\a\ml-commons\ml-commons\plugin\build\tmp\.cache\expanded\zip_ff7bf8f04f99dc306508d1c81e47a68b\jacocoagent.jar=destfile=../../jacoco/test.exec,append=true,inclnolocationclasses=false,dumponexit=true,output=file,jmx=false, -XX:HeapDumpPath=D:\a\ml-commons\ml-commons\plugin\build\heapdump, -Xms512m, -Xmx512m, -Dfile.encoding=UTF-8, -Djava.io.tmpdir=D:\a\ml-commons\ml-commons\plugin\build\testrun\test\temp, -Duser.country=US, -Duser.language=en, -Duser.variant, -ea]
  1> [2025-02-13T13:32:17,855][WARN ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] version [3.0.0-alpha1-SNAPSHOT] is a pre-release version of OpenSearch and is not suitable for production
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] no modules loaded
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.cluster.service.applicationtemplates.TestSystemTemplatesRepositoryPlugin]
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.index.mapper.MockFieldFilterPlugin]
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.ml.plugin.MachineLearningPlugin]
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.node.NodeMocksPlugin]
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.script.MockScriptService$TestPlugin]
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.search.MockSearchService$TestPlugin]
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.MockHttpTransport$TestPlugin]
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.OpenSearchIntegTestCase$AssertActionNamePlugin]
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.OpenSearchIntegTestCase$TestSeedPlugin]
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.TestGeoShapeFieldMapperPlugin]
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.telemetry.MockTelemetryPlugin]
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.transport.MockTransportService$TestPlugin]
  1> [2025-02-13T13:32:17,855][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.transport.nio.MockNioTransportPlugin]
  1> [2025-02-13T13:32:17,871][INFO ][o.o.e.NodeEnvironment    ] [testPredictionWithDataFrame_BatchRCF] using [2] data paths, mounts [[Temporary Storage (D:)]], net usable_space [143.1gb], net total_space [149.9gb], types [NTFS]
  1> [2025-02-13T13:32:17,871][INFO ][o.o.e.NodeEnvironment    ] [testPredictionWithDataFrame_BatchRCF] heap size [512mb], compressed ordinary object pointers [true]
  1> [2025-02-13T13:32:17,871][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] node name [node_s0], node ID [7DGrcz6MRP2UvmMmB4m-jg], cluster name [SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster], roles [ingest, remote_cluster_client, cluster_manager]
  1> [2025-02-13T13:32:17,871][INFO ][o.o.e.ExtensionsManager  ] [testPredictionWithDataFrame_BatchRCF] ExtensionsManager initialized
  1> [2025-02-13T13:32:17,902][INFO ][o.o.r.m.c.i.SdkClientFactory] [testPredictionWithDataFrame_BatchRCF] Using local opensearch cluster as metadata store.
  1> [2025-02-13T13:32:17,902][INFO ][o.o.m.b.MLCircuitBreakerService] [testPredictionWithDataFrame_BatchRCF] Registered ML memory breaker.
  1> [2025-02-13T13:32:17,902][INFO ][o.o.m.b.MLCircuitBreakerService] [testPredictionWithDataFrame_BatchRCF] Registered ML disk breaker.
  1> [2025-02-13T13:32:17,902][INFO ][o.o.m.b.MLCircuitBreakerService] [testPredictionWithDataFrame_BatchRCF] Registered ML native memory breaker.
  1> [2025-02-13T13:32:17,918][INFO ][o.o.d.DiscoveryModule    ] [testPredictionWithDataFrame_BatchRCF] using discovery type [zen] and seed hosts providers [settings, file]
  1> [2025-02-13T13:32:17,933][WARN ][o.o.g.DanglingIndicesState] [testPredictionWithDataFrame_BatchRCF] gateway.auto_import_dangling_indices is disabled, dangling indices will not be automatically detected or imported and must be managed manually
  1> [2025-02-13T13:32:17,949][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] initialized
  1> [2025-02-13T13:32:17,949][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] version[3.0.0-alpha1-SNAPSHOT], pid[2248], build[unknown/38e4b335f5182c0efefc0d88fee733805304f95b/2025-02-13T15:49:48.790936216Z], OS[Windows Server 2022/10.0/amd64], JVM[Azul Systems, Inc./OpenJDK 64-Bit Server VM/23.0.2/23.0.2+7]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] JVM home [C:\hostedtoolcache\windows\jdk\23.0.2\x64]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] JVM arguments [-Dgradle.dist.lib=C:\Users\runneradmin\.gradle\wrapper\dists\gradle-8.11.1-bin\bpt9gzteqjrbo1mjrsomdt32c\gradle-8.11.1\lib, -Dgradle.user.home=C:\Users\runneradmin\.gradle, -Dgradle.worker.jar=C:\Users\runneradmin\.gradle/caches/8.11.1/workerMain/gradle-worker.jar, -Dio.netty.noKeySetOptimization=true, -Dio.netty.noUnsafe=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Djava.awt.headless=true, -Djava.locale.providers=SPI,CLDR, -Djava.security.manager=allow, -Djna.nosys=true, -Dopensearch.scripting.update.ctx_in_params=false, -Dopensearch.search.rewrite_sort=true, -Dopensearch.transport.cname_in_publish_address=true, -Dorg.gradle.internal.worker.tmpdir=D:\a\ml-commons\ml-commons\plugin\build\tmp\test\work, -Dtests.artifact=opensearch-ml-plugin, -Dtests.gradle=true, -Dtests.logger.level=WARN, -Dtests.security.manager=false, -Dtests.seed=F9FEF2C7942CCFB9, -Dtests.task=:opensearch-ml-plugin:test, -Dtests.timeoutSuite=1800000!, -XX:+HeapDumpOnOutOfMemoryError, -esa, -javaagent:D:\a\ml-commons\ml-commons\plugin\build\tmp\.cache\expanded\zip_ff7bf8f04f99dc306508d1c81e47a68b\jacocoagent.jar=destfile=../../jacoco/test.exec,append=true,inclnolocationclasses=false,dumponexit=true,output=file,jmx=false, -XX:HeapDumpPath=D:\a\ml-commons\ml-commons\plugin\build\heapdump, -Xms512m, -Xmx512m, -Dfile.encoding=UTF-8, -Djava.io.tmpdir=D:\a\ml-commons\ml-commons\plugin\build\testrun\test\temp, -Duser.country=US, -Duser.language=en, -Duser.variant, -ea]
  1> [2025-02-13T13:32:17,949][WARN ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] version [3.0.0-alpha1-SNAPSHOT] is a pre-release version of OpenSearch and is not suitable for production
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] no modules loaded
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.cluster.service.applicationtemplates.TestSystemTemplatesRepositoryPlugin]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.index.mapper.MockFieldFilterPlugin]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.ml.plugin.MachineLearningPlugin]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.node.NodeMocksPlugin]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.script.MockScriptService$TestPlugin]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.search.MockSearchService$TestPlugin]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.MockHttpTransport$TestPlugin]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.OpenSearchIntegTestCase$AssertActionNamePlugin]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.OpenSearchIntegTestCase$TestSeedPlugin]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.TestGeoShapeFieldMapperPlugin]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.telemetry.MockTelemetryPlugin]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.transport.MockTransportService$TestPlugin]
  1> [2025-02-13T13:32:17,949][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.transport.nio.MockNioTransportPlugin]
  1> [2025-02-13T13:32:17,965][INFO ][o.o.e.NodeEnvironment    ] [testPredictionWithDataFrame_BatchRCF] using [2] data paths, mounts [[Temporary Storage (D:)]], net usable_space [143.1gb], net total_space [149.9gb], types [NTFS]
  1> [2025-02-13T13:32:17,965][INFO ][o.o.e.NodeEnvironment    ] [testPredictionWithDataFrame_BatchRCF] heap size [512mb], compressed ordinary object pointers [true]
  1> [2025-02-13T13:32:17,965][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] node name [node_s1], node ID [IWKbKUJ-TNqlUspCMhAN2A], cluster name [SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster], roles [ingest, remote_cluster_client, data]
  1> [2025-02-13T13:32:17,965][INFO ][o.o.e.ExtensionsManager  ] [testPredictionWithDataFrame_BatchRCF] ExtensionsManager initialized
  1> [2025-02-13T13:32:17,990][INFO ][o.o.r.m.c.i.SdkClientFactory] [testPredictionWithDataFrame_BatchRCF] Using local opensearch cluster as metadata store.
  1> [2025-02-13T13:32:17,991][INFO ][o.o.m.b.MLCircuitBreakerService] [testPredictionWithDataFrame_BatchRCF] Registered ML memory breaker.
  1> [2025-02-13T13:32:17,991][INFO ][o.o.m.b.MLCircuitBreakerService] [testPredictionWithDataFrame_BatchRCF] Registered ML disk breaker.
  1> [2025-02-13T13:32:17,991][INFO ][o.o.m.b.MLCircuitBreakerService] [testPredictionWithDataFrame_BatchRCF] Registered ML native memory breaker.
  1> [2025-02-13T13:32:17,995][INFO ][o.o.d.DiscoveryModule    ] [testPredictionWithDataFrame_BatchRCF] using discovery type [zen] and seed hosts providers [settings, file]
  1> [2025-02-13T13:32:18,011][WARN ][o.o.g.DanglingIndicesState] [testPredictionWithDataFrame_BatchRCF] gateway.auto_import_dangling_indices is disabled, dangling indices will not be automatically detected or imported and must be managed manually
  1> [2025-02-13T13:32:18,036][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] initialized
  1> [2025-02-13T13:32:18,036][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] version[3.0.0-alpha1-SNAPSHOT], pid[2248], build[unknown/38e4b335f5182c0efefc0d88fee733805304f95b/2025-02-13T15:49:48.790936216Z], OS[Windows Server 2022/10.0/amd64], JVM[Azul Systems, Inc./OpenJDK 64-Bit Server VM/23.0.2/23.0.2+7]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] JVM home [C:\hostedtoolcache\windows\jdk\23.0.2\x64]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] JVM arguments [-Dgradle.dist.lib=C:\Users\runneradmin\.gradle\wrapper\dists\gradle-8.11.1-bin\bpt9gzteqjrbo1mjrsomdt32c\gradle-8.11.1\lib, -Dgradle.user.home=C:\Users\runneradmin\.gradle, -Dgradle.worker.jar=C:\Users\runneradmin\.gradle/caches/8.11.1/workerMain/gradle-worker.jar, -Dio.netty.noKeySetOptimization=true, -Dio.netty.noUnsafe=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Djava.awt.headless=true, -Djava.locale.providers=SPI,CLDR, -Djava.security.manager=allow, -Djna.nosys=true, -Dopensearch.scripting.update.ctx_in_params=false, -Dopensearch.search.rewrite_sort=true, -Dopensearch.transport.cname_in_publish_address=true, -Dorg.gradle.internal.worker.tmpdir=D:\a\ml-commons\ml-commons\plugin\build\tmp\test\work, -Dtests.artifact=opensearch-ml-plugin, -Dtests.gradle=true, -Dtests.logger.level=WARN, -Dtests.security.manager=false, -Dtests.seed=F9FEF2C7942CCFB9, -Dtests.task=:opensearch-ml-plugin:test, -Dtests.timeoutSuite=1800000!, -XX:+HeapDumpOnOutOfMemoryError, -esa, -javaagent:D:\a\ml-commons\ml-commons\plugin\build\tmp\.cache\expanded\zip_ff7bf8f04f99dc306508d1c81e47a68b\jacocoagent.jar=destfile=../../jacoco/test.exec,append=true,inclnolocationclasses=false,dumponexit=true,output=file,jmx=false, -XX:HeapDumpPath=D:\a\ml-commons\ml-commons\plugin\build\heapdump, -Xms512m, -Xmx512m, -Dfile.encoding=UTF-8, -Djava.io.tmpdir=D:\a\ml-commons\ml-commons\plugin\build\testrun\test\temp, -Duser.country=US, -Duser.language=en, -Duser.variant, -ea]
  1> [2025-02-13T13:32:18,036][WARN ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] version [3.0.0-alpha1-SNAPSHOT] is a pre-release version of OpenSearch and is not suitable for production
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] no modules loaded
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.cluster.service.applicationtemplates.TestSystemTemplatesRepositoryPlugin]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.index.mapper.MockFieldFilterPlugin]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.ml.plugin.MachineLearningPlugin]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.node.NodeMocksPlugin]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.script.MockScriptService$TestPlugin]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.search.MockSearchService$TestPlugin]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.MockHttpTransport$TestPlugin]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.OpenSearchIntegTestCase$AssertActionNamePlugin]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.OpenSearchIntegTestCase$TestSeedPlugin]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.TestGeoShapeFieldMapperPlugin]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.telemetry.MockTelemetryPlugin]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.test.transport.MockTransportService$TestPlugin]
  1> [2025-02-13T13:32:18,036][INFO ][o.o.p.PluginsService     ] [testPredictionWithDataFrame_BatchRCF] loaded plugin [org.opensearch.transport.nio.MockNioTransportPlugin]
  1> [2025-02-13T13:32:18,049][INFO ][o.o.e.NodeEnvironment    ] [testPredictionWithDataFrame_BatchRCF] using [2] data paths, mounts [[Temporary Storage (D:)]], net usable_space [143.1gb], net total_space [149.9gb], types [NTFS]
  1> [2025-02-13T13:32:18,049][INFO ][o.o.e.NodeEnvironment    ] [testPredictionWithDataFrame_BatchRCF] heap size [512mb], compressed ordinary object pointers [true]
  1> [2025-02-13T13:32:18,059][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] node name [node_s2], node ID [9Qwi8paQTmWGK1xS7mpMjg], cluster name [SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster], roles [ingest, remote_cluster_client, data]
  1> [2025-02-13T13:32:18,061][INFO ][o.o.e.ExtensionsManager  ] [testPredictionWithDataFrame_BatchRCF] ExtensionsManager initialized
  1> [2025-02-13T13:32:18,089][INFO ][o.o.r.m.c.i.SdkClientFactory] [testPredictionWithDataFrame_BatchRCF] Using local opensearch cluster as metadata store.
  1> [2025-02-13T13:32:18,089][INFO ][o.o.m.b.MLCircuitBreakerService] [testPredictionWithDataFrame_BatchRCF] Registered ML memory breaker.
  1> [2025-02-13T13:32:18,089][INFO ][o.o.m.b.MLCircuitBreakerService] [testPredictionWithDataFrame_BatchRCF] Registered ML disk breaker.
  1> [2025-02-13T13:32:18,089][INFO ][o.o.m.b.MLCircuitBreakerService] [testPredictionWithDataFrame_BatchRCF] Registered ML native memory breaker.
  1> [2025-02-13T13:32:18,089][INFO ][o.o.d.DiscoveryModule    ] [testPredictionWithDataFrame_BatchRCF] using discovery type [zen] and seed hosts providers [settings, file]
  1> [2025-02-13T13:32:18,109][WARN ][o.o.g.DanglingIndicesState] [testPredictionWithDataFrame_BatchRCF] gateway.auto_import_dangling_indices is disabled, dangling indices will not be automatically detected or imported and must be managed manually
  1> [2025-02-13T13:32:18,128][INFO ][o.o.n.Node               ] [testPredictionWithDataFrame_BatchRCF] initialized
  1> [2025-02-13T13:32:18,154][INFO ][o.o.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster[T#1]]] starting ...
  1> [2025-02-13T13:32:18,154][INFO ][o.o.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster[T#2]]] starting ...
  1> [2025-02-13T13:32:18,154][INFO ][o.o.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster[T#3]]] starting ...
  1> [2025-02-13T13:32:18,171][INFO ][o.o.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster[T#2]]] publish_address {127.0.0.1:53537}, bound_addresses {[::1]:53536}, {127.0.0.1:53537}
  1> [2025-02-13T13:32:18,171][INFO ][o.o.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster[T#2]]] Remote clusters initialized successfully.
  1> [2025-02-13T13:32:18,188][INFO ][o.o.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster[T#1]]] publish_address {127.0.0.1:53539}, bound_addresses {[::1]:53538}, {127.0.0.1:53539}
  1> [2025-02-13T13:32:18,188][INFO ][o.o.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster[T#1]]] Remote clusters initialized successfully.
  1> [2025-02-13T13:32:18,192][INFO ][o.o.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster[T#3]]] publish_address {127.0.0.1:53541}, bound_addresses {[::1]:53540}, {127.0.0.1:53541}
  1> [2025-02-13T13:32:18,192][INFO ][o.o.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster[T#3]]] Remote clusters initialized successfully.
  1> [2025-02-13T13:32:18,248][INFO ][o.o.c.c.Coordinator      ] [[test_SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster[T#1]]] setting initial configuration to VotingConfiguration{7DGrcz6MRP2UvmMmB4m-jg}
  1> [2025-02-13T13:32:18,380][INFO ][o.o.c.s.ClusterManagerService] [node_s0] Tasks batched with key: org.opensearch.cluster.coordination.JoinHelper, count:3 and sample tasks: elected-as-cluster-manager ([1] nodes joined)[{node_s0}{7DGrcz6MRP2UvmMmB4m-jg}{IU4UDSYeSkKbgCG-jSpGvg}{127.0.0.1}{127.0.0.1:53539}{imr}{shard_indexing_pressure_enabled=true} elect leader, _BECOME_CLUSTER_MANAGER_TASK_, _FINISH_ELECTION_], term: 1, version: 1, delta: cluster-manager node changed {previous [], current [{node_s0}{7DGrcz6MRP2UvmMmB4m-jg}{IU4UDSYeSkKbgCG-jSpGvg}{127.0.0.1}{127.0.0.1:53539}{imr}{shard_indexing_pressure_enabled=true}]}
  1> [2025-02-13T13:32:18,388][INFO ][o.o.c.c.CoordinationState] [node_s0] cluster UUID set to [9fvBKnZrSYyijSgnnRw5hg]
  1> [2025-02-13T13:32:18,433][INFO ][o.o.c.s.ClusterApplierService] [node_s0] cluster-manager node changed {previous [], current [{node_s0}{7DGrcz6MRP2UvmMmB4m-jg}{IU4UDSYeSkKbgCG-jSpGvg}{127.0.0.1}{127.0.0.1:53539}{imr}{shard_indexing_pressure_enabled=true}]}, term: 1, version: 1, reason: Publication{term=1, version=1}
  1> [2025-02-13T13:32:18,435][INFO ][o.o.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster[T#1]]] started
  1> [2025-02-13T13:32:18,436][INFO ][o.o.d.PeerFinder         ] [node_s0] setting findPeersInterval to [1s] as node commission status = [true] for local node [{node_s0}{7DGrcz6MRP2UvmMmB4m-jg}{IU4UDSYeSkKbgCG-jSpGvg}{127.0.0.1}{127.0.0.1:53539}{imr}{shard_indexing_pressure_enabled=true}]
  1> [2025-02-13T13:32:18,436][WARN ][o.o.c.r.a.AllocationService] [node_s0] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
  1> [2025-02-13T13:32:18,437][WARN ][o.o.c.r.a.AllocationService] [node_s0] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
  1> [2025-02-13T13:32:18,443][INFO ][o.o.g.GatewayService     ] [node_s0] recovered [0] indices into cluster_state
  1> [2025-02-13T13:32:18,445][INFO ][o.o.m.a.MLModelAutoReDeployer] [node_s0] Index not found, not performing auto reloading!
  1> [2025-02-13T13:32:19,274][INFO ][o.o.c.s.ClusterManagerService] [node_s0] Tasks batched with key: org.opensearch.cluster.coordination.JoinHelper, count:1 and sample tasks: node-join[{node_s2}{9Qwi8paQTmWGK1xS7mpMjg}{ZLe_aVHMS_WyEGWMmzTwYQ}{127.0.0.1}{127.0.0.1:53541}{dir}{shard_indexing_pressure_enabled=true} join existing leader], term: 1, version: 3, delta: added {{node_s2}{9Qwi8paQTmWGK1xS7mpMjg}{ZLe_aVHMS_WyEGWMmzTwYQ}{127.0.0.1}{127.0.0.1:53541}{dir}{shard_indexing_pressure_enabled=true}}
  1> [2025-02-13T13:32:19,293][INFO ][o.o.c.s.ClusterApplierService] [node_s2] cluster-manager node changed {previous [], current [{node_s0}{7DGrcz6MRP2UvmMmB4m-jg}{IU4UDSYeSkKbgCG-jSpGvg}{127.0.0.1}{127.0.0.1:53539}{imr}{shard_indexing_pressure_enabled=true}]}, added {{node_s0}{7DGrcz6MRP2UvmMmB4m-jg}{IU4UDSYeSkKbgCG-jSpGvg}{127.0.0.1}{127.0.0.1:53539}{imr}{shard_indexing_pressure_enabled=true}}, term: 1, version: 3, reason: ApplyCommitRequest{term=1, version=3, sourceNode={node_s0}{7DGrcz6MRP2UvmMmB4m-jg}{IU4UDSYeSkKbgCG-jSpGvg}{127.0.0.1}{127.0.0.1:53539}{imr}}
  1> [2025-02-13T13:32:19,293][INFO ][o.o.m.a.MLModelAutoReDeployer] [node_s2] model auto reloading should be initialized by cluster manager node only, current node id is empty or current node not cluster manager!
  1> [2025-02-13T13:32:19,295][INFO ][o.o.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster[T#3]]] started
  1> [2025-02-13T13:32:19,295][INFO ][o.o.c.s.ClusterApplierService] [node_s0] added {{node_s2}{9Qwi8paQTmWGK1xS7mpMjg}{ZLe_aVHMS_WyEGWMmzTwYQ}{127.0.0.1}{127.0.0.1:53541}{dir}{shard_indexing_pressure_enabled=true}}, term: 1, version: 3, reason: Publication{term=1, version=3}
  1> [2025-02-13T13:32:19,295][INFO ][o.o.m.a.MLModelAutoReDeployer] [node_s0] Index not found, not performing auto reloading!
  1> [2025-02-13T13:32:19,301][INFO ][o.o.d.PeerFinder         ] [node_s2] setting findPeersInterval to [1s] as node commission status = [true] for local node [{node_s2}{9Qwi8paQTmWGK1xS7mpMjg}{ZLe_aVHMS_WyEGWMmzTwYQ}{127.0.0.1}{127.0.0.1:53541}{dir}{shard_indexing_pressure_enabled=true}]
  1> [2025-02-13T13:32:19,301][INFO ][o.o.c.s.ClusterManagerService] [node_s0] Tasks batched with key: org.opensearch.cluster.coordination.JoinHelper, count:1 and sample tasks: node-join[{node_s1}{IWKbKUJ-TNqlUspCMhAN2A}{VlEDPwh4T_KfaR5HH85Tfw}{127.0.0.1}{127.0.0.1:53537}{dir}{shard_indexing_pressure_enabled=true} join existing leader], term: 1, version: 4, delta: added {{node_s1}{IWKbKUJ-TNqlUspCMhAN2A}{VlEDPwh4T_KfaR5HH85Tfw}{127.0.0.1}{127.0.0.1:53537}{dir}{shard_indexing_pressure_enabled=true}}
  1> [2025-02-13T13:32:19,326][INFO ][o.o.c.s.ClusterApplierService] [node_s2] added {{node_s1}{IWKbKUJ-TNqlUspCMhAN2A}{VlEDPwh4T_KfaR5HH85Tfw}{127.0.0.1}{127.0.0.1:53537}{dir}{shard_indexing_pressure_enabled=true}}, term: 1, version: 4, reason: ApplyCommitRequest{term=1, version=4, sourceNode={node_s0}{7DGrcz6MRP2UvmMmB4m-jg}{IU4UDSYeSkKbgCG-jSpGvg}{127.0.0.1}{127.0.0.1:53539}{imr}}
  1> [2025-02-13T13:32:19,328][INFO ][o.o.c.s.ClusterApplierService] [node_s1] cluster-manager node changed {previous [], current [{node_s0}{7DGrcz6MRP2UvmMmB4m-jg}{IU4UDSYeSkKbgCG-jSpGvg}{127.0.0.1}{127.0.0.1:53539}{imr}{shard_indexing_pressure_enabled=true}]}, added {{node_s0}{7DGrcz6MRP2UvmMmB4m-jg}{IU4UDSYeSkKbgCG-jSpGvg}{127.0.0.1}{127.0.0.1:53539}{imr}{shard_indexing_pressure_enabled=true},{node_s2}{9Qwi8paQTmWGK1xS7mpMjg}{ZLe_aVHMS_WyEGWMmzTwYQ}{127.0.0.1}{127.0.0.1:53541}{dir}{shard_indexing_pressure_enabled=true}}, term: 1, version: 4, reason: ApplyCommitRequest{term=1, version=4, sourceNode={node_s0}{7DGrcz6MRP2UvmMmB4m-jg}{IU4UDSYeSkKbgCG-jSpGvg}{127.0.0.1}{127.0.0.1:53539}{imr}}
  1> [2025-02-13T13:32:19,337][INFO ][o.o.m.a.MLModelAutoReDeployer] [node_s2] model auto reloading should be initialized by cluster manager node only, current node id is empty or current node not cluster manager!
  1> [2025-02-13T13:32:19,337][INFO ][o.o.m.a.MLModelAutoReDeployer] [node_s1] model auto reloading should be initialized by cluster manager node only, current node id is empty or current node not cluster manager!
  1> [2025-02-13T13:32:19,337][INFO ][o.o.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[7]-CLUSTER_SEED=[-636854191491553770]-HASH=[265FAD580D8]-cluster[T#2]]] started
  1> [2025-02-13T13:32:19,342][INFO ][o.o.c.s.ClusterApplierService] [node_s0] added {{node_s1}{IWKbKUJ-TNqlUspCMhAN2A}{VlEDPwh4T_KfaR5HH85Tfw}{127.0.0.1}{127.0.0.1:53537}{dir}{shard_indexing_pressure_enabled=true}}, term: 1, version: 4, reason: Publication{term=1, version=4}
  1> [2025-02-13T13:32:19,343][INFO ][o.o.m.a.MLModelAutoReDeployer] [node_s0] Index not found, not performing auto reloading!
  1> [2025-02-13T13:32:19,345][INFO ][o.o.d.PeerFinder         ] [node_s1] setting findPeersInterval to [1s] as node commission status = [true] for local node [{node_s1}{IWKbKUJ-TNqlUspCMhAN2A}{VlEDPwh4T_KfaR5HH85Tfw}{127.0.0.1}{127.0.0.1:53537}{dir}{shard_indexing_pressure_enabled=true}]
  1> [2025-02-13T13:32:19,346][WARN ][o.o.c.r.a.AllocationService] [node_s0] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
  1> [2025-02-13T13:32:19,346][WARN ][o.o.c.r.a.AllocationService] [node_s0] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
  1> [2025-02-13T13:32:19,364][INFO ][o.o.p.PluginsService     ] [node_s0] PluginService:onIndexModule index:[2m5Vu7b5TcO54QejuWcxBg/-zbIFAJqTLGi5BTPvjcZ_w]
  1> [2025-02-13T13:32:19,364][INFO ][o.o.c.m.MetadataIndexTemplateService] [node_s0] adding template [random_index_template] for index patterns [*]
  1> [2025-02-13T13:32:19,404][INFO ][o.o.t.OpenSearchTestClusterRule] [testPredictionWithDataFrame_BatchRCF] [PredictionITTests#testPredictionWithDataFrame_BatchRCF]: all set up test
  1> [2025-02-13T13:32:19,404][INFO ][o.o.m.a.p.PredictionITTests] [testPredictionWithDataFrame_BatchRCF] before test
  1> [2025-02-13T13:32:19,419][INFO ][o.o.p.PluginsService     ] [node_s0] PluginService:onIndexModule index:[iris_data_for_prediction_it/2ysizb39Re-6C9hAyIE1AQ]
  1> [2025-02-13T13:32:19,435][INFO ][o.o.c.m.MetadataCreateIndexService] [node_s0] [iris_data_for_prediction_it] creating index, cause [auto(bulk api)], templates [random_index_template], shards [1]/[0]
  1> [2025-02-13T13:32:19,435][WARN ][o.o.c.r.a.AllocationService] [node_s0] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
  1> [2025-02-13T13:32:19,595][INFO ][o.o.p.PluginsService     ] [node_s1] PluginService:onIndexModule index:[iris_data_for_prediction_it/2ysizb39Re-6C9hAyIE1AQ]
  1> [2025-02-13T13:32:19,639][INFO ][o.o.c.r.a.AllocationService] [node_s0] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[iris_data_for_prediction_it][0]]]).
  1> [2025-02-13T13:32:19,758][WARN ][o.o.c.r.a.AllocationService] [node_s0] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
  1> [2025-02-13T13:32:19,952][INFO ][o.o.p.PluginsService     ] [node_s0] PluginService:onIndexModule index:[iris_data_for_prediction_it/2ysizb39Re-6C9hAyIE1AQ]
  1> [2025-02-13T13:32:19,967][INFO ][o.o.c.m.MetadataMappingService] [node_s0] [iris_data_for_prediction_it/2ysizb39Re-6C9hAyIE1AQ] create_mapping
  1> [2025-02-13T13:32:20,993][INFO ][o.o.p.PluginsService     ] [node_s0] PluginService:onIndexModule index:[.plugins-ml-model/gHLqksA9RjKRqNTwbUED5g]
  1> [2025-02-13T13:32:21,043][INFO ][o.o.c.m.MetadataCreateIndexService] [node_s0] [.plugins-ml-model] creating index, cause [api], templates [], shards [1]/[1]
  1> [2025-02-13T13:32:21,057][WARN ][o.o.c.r.a.AllocationService] [node_s0] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
  1> [2025-02-13T13:32:21,105][INFO ][o.o.p.PluginsService     ] [node_s2] PluginService:onIndexModule index:[.plugins-ml-model/gHLqksA9RjKRqNTwbUED5g]
  1> [2025-02-13T13:32:21,248][INFO ][o.o.m.e.i.MLIndicesHandler] [node_s2] create index:.plugins-ml-model
  1> [2025-02-13T13:32:21,251][WARN ][o.o.c.r.a.AllocationService] [node_s0] Falling back to single shard assignment since batch mode disable or multiple custom allocators set
  1> [2025-02-13T13:32:21,267][INFO ][o.o.p.PluginsService     ] [node_s1] PluginService:onIndexModule index:[.plugins-ml-model/gHLqksA9RjKRqNTwbUED5g]
  1> [2025-02-13T13:32:21,387][INFO ][o.o.m.t.MLTrainingTaskRunner] [node_s2] Model saved into index, result:CREATED, model id: FdM6AZUB4SCHPZwhHyuC
  2> فبراير 13, 2025 1:32:23 م org.tribuo.common.sgd.AbstractSGDTrainer train
  2> INFO: Training SGD model with 100 examples
  2> فبراير 13, 2025 1:32:23 م org.tribuo.common.sgd.AbstractSGDTrainer train
  2> INFO: Outputs - RegressionInfo({name=price,id=0,count=100,max=99.000000,min=0.000000,mean=49.500000,variance=841.666667})
  2> فبراير 13, 2025 1:32:24 م org.tribuo.common.sgd.AbstractSGDTrainer train
  2> INFO: Training SGD model with 150 examples
  2> فبراير 13, 2025 1:32:24 م org.tribuo.common.sgd.AbstractSGDTrainer train
  2> INFO: Outputs - (0,Iris-versicolor,50), (1,Iris-virginica,50), (2,Iris-setosa,50)

How can one reproduce the bug?
Steps to reproduce the behavior:

  1. Go to '...'
  2. Click on '....'
  3. Scroll down to '....'
  4. See error

What is the expected behavior?
A clear and concise description of what you expected to happen.

What is your host/environment?

  • OS: [e.g. iOS]
  • Version [e.g. 22]
  • Plugins

Do you have any screenshots?
If applicable, add screenshots to help explain your problem.

Do you have any additional context?
Add any other context about the problem.
@rithin-pullela-aws rithin-pullela-aws added bug Something isn't working untriaged labels Feb 14, 2025
@rithin-pullela-aws rithin-pullela-aws changed the title [BUG] [Flaky Test] PredictionITTests.testPredictionWithDataFrame_BatchRCF is falky [BUG] [Flaky Test] PredictionITTests are being flaky Feb 14, 2025
@rithin-pullela-aws
Copy link
Contributor Author

My experimentation and Findings:
From the log it can be seen that there is a race condition:

java.util.ConcurrentModificationException
...
at org.opensearch.common.logging.Loggers.removeAppender(Loggers.java:176)
at org.opensearch.test.OpenSearchTestCase.removeHeaderWarningAppender(OpenSearchTestCase.java:411)
...

I reproduced this locally by running:

./gradlew ':opensearch-ml-plugin:test' \
 --tests "org.opensearch.ml.action.prediction.PredictionITTests"

Many of the tests in PredictionITTests.java failed intermittently with the same stack trace. The key point is that OpenSearchTestCase.removeHeaderWarningAppender()—an @after method—throws a ConcurrentModificationException because multiple threads are concurrently touching a non‐concurrent data structure in Log4j. Even when I run a single test case (i.e., no parallel test classes), this is still failing flakily, indicating some internal thread is modifying the logger registry at the same time causing the ConcurrentModificationException.

Because this happens in the teardown method, JUnit sees it as a test failure even though the main test logic has already passed.

Potential solution: Adding retry

@dhrubo-os dhrubo-os moved this to On-deck in ml-commons projects Feb 25, 2025
@rithin-pullela-aws rithin-pullela-aws mentioned this issue Mar 12, 2025
Closed
5 tasks
@dhrubo-os
Copy link
Collaborator 

opensearch.ml.action.prediction.PredictionITTests"

Many of the tests in PredictionITTests.java failed intermittently with the same stack trace. The key point is that OpenSearchTestCase.removeHeaderWarningAppender()—an @after method—throws a ConcurrentModificationException because multiple threads are concurrently touching a non‐concurrent data structure in Log4j. Even when I run a single test case (i.e., no parallel test classes), this is still failing flakily, indicating some internal thread is modifying the logger registry at the same time causing the ConcurrentModificationException.

Because this happens in the teardown method, JUnit sees it as a test failure even though the main test logic has already passed.

Potential solution: Adding retry

Retrying could temporarily reduce failures, but it doesn't guarantee a fix—there's always a chance of failure if threads are modifying the logger at just the wrong moment. Have you considered any other approaches?

@dhrubo-os
Copy link
Collaborator

Can you check what other plugins or core do that in this case? Do we need to override this method in our end?

@rithin-pullela-aws
Copy link
Contributor Author

Can you check what other plugins or core do that in this case? Do we need to override this method in our end?

We cannot override methods annotated with @ After in open search.

@rithin-pullela-aws
Copy link
Contributor Author

Update: The error is originating from log4j.core, OpenSearch core depends on 2.21.0
But we forced the log4j-core to version 2.24.2 here.

The 2.24.2 version introduced a bug causing the ConcurrentModificationException: Ref.

Using the log4j version that is used in the core would resolve this issue.

@rithin-pullela-aws rithin-pullela-aws mentioned this issue Mar 13, 2025
Merged
5 tasks
@nathaliellenaa nathaliellenaa mentioned this issue Mar 14, 2025
Open
5 tasks
@github-project-automation github-project-automation bot moved this from On-deck to Done in ml-commons projects Mar 14, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@rithin-pullela-aws rithin-pullela-aws

Labels
bug Something isn't working
Projects
ml-commons projects
Status: Done
Milestone
No milestone
2 participants
@dhrubo-os @rithin-pullela-aws