[CI] HistoryActionConditionTests.testActionConditionWithFailures fails

[valeriy42]

Build scan: https://gradle-enterprise.elastic.co/s/mgjvcngsp5tp2

Repro line:

./gradlew ':x-pack:plugin:watcher:internalClusterTest' --tests "org.elasticsearch.xpack.watcher.history.HistoryActionConditionTests.testActionConditionWithFailures" -Dtests.seed=26E928EADEF031A0 -Dtests.security.manager=true -Dtests.locale=lt -Dtests.timezone=Pacific/Auckland -Druntime.java=11

Reproduces locally?: No

Applicable branches: master

Failure history:

https://build-stats.elastic.co/app/kibana#/discover?_g=(refreshInterval:(pause:!t,value:0),time:(from:now-7d,mode:quick,to:now))&_a=(columns:!(_source),index:b646ed00-7efc-11e8-bf69-63c8ef516157,interval:auto,query:(language:lucene,query:testActionConditionWithFailures),sort:!(process.time-start,desc))

Failure excerpt:

[2020-11-16T19:39:28,894][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] before test
[2020-11-16T19:39:28,908][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] [HistoryActionConditionTests#testActionConditionWithFailures]: setting up test
[2020-11-16T19:39:28,969][INFO ][o.e.t.InternalTestCluster] [testActionConditionWithFailures] Setup InternalTestCluster [SUITE-TEST_WORKER_VM=[909]-CLUSTER_SEED=[-5106983454815968100]-HASH=[2F7433B96A7]-cluster] with seed [B920599B15E5A49C] using [0] dedicated masters, [2] (data) nodes and [0] coord only nodes (master nodes are [auto-managed])
[2020-11-16T19:39:29,553][INFO ][o.e.n.Node               ] [testActionConditionWithFailures] version[8.0.0-SNAPSHOT], pid[344905], build[unknown/unknown/c2864e38fb097bd0e8095aaa716263356a0c3f8a/2020-11-16T05:46:36.197719Z], OS[Linux/5.8.18-200.fc32.x86_64/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/11.0.2/11.0.2+7]
[2020-11-16T19:39:29,554][INFO ][o.e.n.Node               ] [testActionConditionWithFailures] JVM home [/var/lib/jenkins/.java/openjdk-11.0.2-linux]
[2020-11-16T19:39:29,559][DEPRECATION][o.e.d.n.Node             ] [testActionConditionWithFailures] data_stream.dataset="deprecation.elasticsearch" data_stream.namespace="default" data_stream.type="logs" ecs.version="1.6" key="no-jdk" message="no-jdk distributions that do not bundle a JDK are deprecated and will be removed in a future release"
[2020-11-16T19:39:29,560][INFO ][o.e.n.Node               ] [testActionConditionWithFailures] JVM arguments [-Dfile.encoding=UTF8, -Des.scripting.update.ctx_in_params=false, -Des.search.rewrite_sort=true, -Des.set.netty.runtime.available.processors=false, -Des.transport.cname_in_publish_address=true, -Dgradle.dist.lib=/var/lib/jenkins/.gradle/wrapper/dists/gradle-6.6.1-all/ejrtlte9hlw8v6ii20a9584rs/gradle-6.6.1/lib, -Dgradle.user.home=/var/lib/jenkins/.gradle, -Dgradle.worker.jar=/var/lib/jenkins/.gradle/caches/6.6.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,COMPAT, -Djna.nosys=true, -Dorg.gradle.native=false, -Dtests.artifact=watcher, -Dtests.gradle=true, -Dtests.logger.level=WARN, -Dtests.security.manager=true, -Dtests.seed=26E928EADEF031A0, -Dtests.task=:x-pack:plugin:watcher:internalClusterTest, --illegal-access=warn, -XX:+HeapDumpOnOutOfMemoryError, -esa, -XX:HeapDumpPath=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora-32&&immutable/x-pack/plugin/watcher/build/heapdump, -Xms512m, -Xmx512m, -Dfile.encoding=UTF-8, -Djava.io.tmpdir=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora-32&&immutable/x-pack/plugin/watcher/build/testrun/internalClusterTest/temp, -Duser.country=US, -Duser.language=en, -Duser.variant, -ea]
[2020-11-16T19:39:29,561][WARN ][o.e.n.Node               ] [testActionConditionWithFailures] version [8.0.0-SNAPSHOT] is a pre-release version of Elasticsearch and is not suitable for production
[2020-11-16T19:39:29,582][INFO ][o.e.x.w.t.TimeWarpedWatcher] [testActionConditionWithFailures] using time warped watchers plugin
[2020-11-16T19:39:29,620][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] no modules loaded
[2020-11-16T19:39:29,622][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.analysis.common.CommonAnalysisPlugin]
[2020-11-16T19:39:29,622][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.script.MockMustacheScriptEngine$TestPlugin]
[2020-11-16T19:39:29,623][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.script.MockScriptService$TestPlugin]
[2020-11-16T19:39:29,623][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.test.ESIntegTestCase$AssertActionNamePlugin]
[2020-11-16T19:39:29,623][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
[2020-11-16T19:39:29,633][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.test.MockHttpTransport$TestPlugin]
[2020-11-16T19:39:29,633][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.test.TestGeoShapeFieldMapperPlugin]
[2020-11-16T19:39:29,634][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.test.store.MockFSIndexStore$TestPlugin]
[2020-11-16T19:39:29,635][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
[2020-11-16T19:39:29,635][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.xpack.datastreams.DataStreamsPlugin]
[2020-11-16T19:39:29,636][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.xpack.ilm.IndexLifecycle]
[2020-11-16T19:39:29,636][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.xpack.watcher.history.HistoryActionConditionTests$CustomScriptPlugin]
[2020-11-16T19:39:29,636][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.xpack.watcher.test.TimeWarpedWatcher]
[2020-11-16T19:39:29,748][INFO ][o.e.e.NodeEnvironment    ] [testActionConditionWithFailures] using [1] data paths, mounts [[/ (/dev/sda1)]], net usable_space [201gb], net total_space [344.4gb], types [ext4]
[2020-11-16T19:39:29,749][INFO ][o.e.e.NodeEnvironment    ] [testActionConditionWithFailures] heap size [512mb], compressed ordinary object pointers [true]
[2020-11-16T19:39:29,829][INFO ][o.e.n.Node               ] [testActionConditionWithFailures] node name [node_s0], node ID [WlosICA8SIGc2o_vrpJRFw], cluster name [SUITE-TEST_WORKER_VM=[909]-CLUSTER_SEED=[-5106983454815968100]-HASH=[2F7433B96A7]-cluster], roles [remote_cluster_client, data_hot, data_content, ingest, data_warm, data, data_cold, master]
[2020-11-16T19:39:33,530][INFO ][o.e.d.DiscoveryModule    ] [testActionConditionWithFailures] using discovery type [zen] and seed hosts providers [settings, file]
[2020-11-16T19:39:34,515][INFO ][o.e.n.Node               ] [testActionConditionWithFailures] initialized
[2020-11-16T19:39:34,521][INFO ][o.e.n.Node               ] [testActionConditionWithFailures] version[8.0.0-SNAPSHOT], pid[344905], build[unknown/unknown/c2864e38fb097bd0e8095aaa716263356a0c3f8a/2020-11-16T05:46:36.197719Z], OS[Linux/5.8.18-200.fc32.x86_64/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/11.0.2/11.0.2+7]
[2020-11-16T19:39:34,522][INFO ][o.e.n.Node               ] [testActionConditionWithFailures] JVM home [/var/lib/jenkins/.java/openjdk-11.0.2-linux]
[2020-11-16T19:39:34,523][DEPRECATION][o.e.d.n.Node             ] [testActionConditionWithFailures] data_stream.dataset="deprecation.elasticsearch" data_stream.namespace="default" data_stream.type="logs" ecs.version="1.6" key="no-jdk" message="no-jdk distributions that do not bundle a JDK are deprecated and will be removed in a future release"
[2020-11-16T19:39:34,524][INFO ][o.e.n.Node               ] [testActionConditionWithFailures] JVM arguments [-Dfile.encoding=UTF8, -Des.scripting.update.ctx_in_params=false, -Des.search.rewrite_sort=true, -Des.set.netty.runtime.available.processors=false, -Des.transport.cname_in_publish_address=true, -Dgradle.dist.lib=/var/lib/jenkins/.gradle/wrapper/dists/gradle-6.6.1-all/ejrtlte9hlw8v6ii20a9584rs/gradle-6.6.1/lib, -Dgradle.user.home=/var/lib/jenkins/.gradle, -Dgradle.worker.jar=/var/lib/jenkins/.gradle/caches/6.6.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,COMPAT, -Djna.nosys=true, -Dorg.gradle.native=false, -Dtests.artifact=watcher, -Dtests.gradle=true, -Dtests.logger.level=WARN, -Dtests.security.manager=true, -Dtests.seed=26E928EADEF031A0, -Dtests.task=:x-pack:plugin:watcher:internalClusterTest, --illegal-access=warn, -XX:+HeapDumpOnOutOfMemoryError, -esa, -XX:HeapDumpPath=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora-32&&immutable/x-pack/plugin/watcher/build/heapdump, -Xms512m, -Xmx512m, -Dfile.encoding=UTF-8, -Djava.io.tmpdir=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora-32&&immutable/x-pack/plugin/watcher/build/testrun/internalClusterTest/temp, -Duser.country=US, -Duser.language=en, -Duser.variant, -ea]
[2020-11-16T19:39:34,526][WARN ][o.e.n.Node               ] [testActionConditionWithFailures] version [8.0.0-SNAPSHOT] is a pre-release version of Elasticsearch and is not suitable for production
[2020-11-16T19:39:34,527][INFO ][o.e.x.w.t.TimeWarpedWatcher] [testActionConditionWithFailures] using time warped watchers plugin
[2020-11-16T19:39:34,532][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] no modules loaded
[2020-11-16T19:39:34,534][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.analysis.common.CommonAnalysisPlugin]
[2020-11-16T19:39:34,534][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.script.MockMustacheScriptEngine$TestPlugin]
[2020-11-16T19:39:34,534][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.script.MockScriptService$TestPlugin]
[2020-11-16T19:39:34,535][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.test.ESIntegTestCase$AssertActionNamePlugin]
[2020-11-16T19:39:34,536][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
[2020-11-16T19:39:34,536][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.test.MockHttpTransport$TestPlugin]
[2020-11-16T19:39:34,537][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.test.TestGeoShapeFieldMapperPlugin]
[2020-11-16T19:39:34,537][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.test.store.MockFSIndexStore$TestPlugin]
[2020-11-16T19:39:34,537][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
[2020-11-16T19:39:34,538][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.xpack.datastreams.DataStreamsPlugin]
[2020-11-16T19:39:34,538][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.xpack.ilm.IndexLifecycle]
[2020-11-16T19:39:34,539][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.xpack.watcher.history.HistoryActionConditionTests$CustomScriptPlugin]
[2020-11-16T19:39:34,539][INFO ][o.e.p.PluginsService     ] [testActionConditionWithFailures] loaded plugin [org.elasticsearch.xpack.watcher.test.TimeWarpedWatcher]
[2020-11-16T19:39:34,549][INFO ][o.e.e.NodeEnvironment    ] [testActionConditionWithFailures] using [1] data paths, mounts [[/ (/dev/sda1)]], net usable_space [201gb], net total_space [344.4gb], types [ext4]
[2020-11-16T19:39:34,549][INFO ][o.e.e.NodeEnvironment    ] [testActionConditionWithFailures] heap size [512mb], compressed ordinary object pointers [true]
[2020-11-16T19:39:34,553][INFO ][o.e.n.Node               ] [testActionConditionWithFailures] node name [node_s1], node ID [NsN10n-yRbuRWH96zYC7zA], cluster name [SUITE-TEST_WORKER_VM=[909]-CLUSTER_SEED=[-5106983454815968100]-HASH=[2F7433B96A7]-cluster], roles [remote_cluster_client, data_hot, data_content, ingest, data_warm, data, data_cold, master]
[2020-11-16T19:39:34,648][INFO ][o.e.d.DiscoveryModule    ] [testActionConditionWithFailures] using discovery type [zen] and seed hosts providers [settings, file]
[2020-11-16T19:39:34,756][INFO ][o.e.n.Node               ] [testActionConditionWithFailures] initialized
[2020-11-16T19:39:34,769][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[909]-CLUSTER_SEED=[-5106983454815968100]-HASH=[2F7433B96A7]-cluster[T#1]]] starting ...
[2020-11-16T19:39:34,769][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[909]-CLUSTER_SEED=[-5106983454815968100]-HASH=[2F7433B96A7]-cluster[T#2]]] starting ...
[2020-11-16T19:39:34,891][INFO ][o.e.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[909]-CLUSTER_SEED=[-5106983454815968100]-HASH=[2F7433B96A7]-cluster[T#2]]] publish_address {127.0.0.1:42163}, bound_addresses {[::1]:41031}, {127.0.0.1:42163}
[2020-11-16T19:39:34,893][INFO ][o.e.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[909]-CLUSTER_SEED=[-5106983454815968100]-HASH=[2F7433B96A7]-cluster[T#1]]] publish_address {127.0.0.1:34179}, bound_addresses {[::1]:33141}, {127.0.0.1:34179}
[2020-11-16T19:39:35,547][INFO ][o.e.c.c.Coordinator      ] [node_s1] setting initial configuration to VotingConfiguration{WlosICA8SIGc2o_vrpJRFw,NsN10n-yRbuRWH96zYC7zA}
[2020-11-16T19:39:35,883][INFO ][o.e.c.s.MasterService    ] [node_s1] elected-as-master ([2] nodes joined)[{node_s0}{WlosICA8SIGc2o_vrpJRFw}{qggjhhvURIm1P3Wj6YMTlg}{127.0.0.1}{127.0.0.1:34179}{cdhimrsw}{xpack.installed=true} elect leader, {node_s1}{NsN10n-yRbuRWH96zYC7zA}{eKPutz8vSFqVUwlqw0w2pw}{127.0.0.1}{127.0.0.1:42163}{cdhimrsw}{xpack.installed=true} elect leader, _BECOME_MASTER_TASK_, _FINISH_ELECTION_], term: 1, version: 1, delta: master node changed {previous [], current [{node_s1}{NsN10n-yRbuRWH96zYC7zA}{eKPutz8vSFqVUwlqw0w2pw}{127.0.0.1}{127.0.0.1:42163}{cdhimrsw}{xpack.installed=true}]}, added {{node_s0}{WlosICA8SIGc2o_vrpJRFw}{qggjhhvURIm1P3Wj6YMTlg}{127.0.0.1}{127.0.0.1:34179}{cdhimrsw}{xpack.installed=true}}
[2020-11-16T19:39:36,016][INFO ][o.e.c.c.CoordinationState] [node_s1] cluster UUID set to [X3q_00g9SMWpG8pQMI1WAw]
[2020-11-16T19:39:36,016][INFO ][o.e.c.c.CoordinationState] [node_s0] cluster UUID set to [X3q_00g9SMWpG8pQMI1WAw]
[2020-11-16T19:39:36,172][INFO ][o.e.c.s.ClusterApplierService] [node_s0] master node changed {previous [], current [{node_s1}{NsN10n-yRbuRWH96zYC7zA}{eKPutz8vSFqVUwlqw0w2pw}{127.0.0.1}{127.0.0.1:42163}{cdhimrsw}{xpack.installed=true}]}, added {{node_s1}{NsN10n-yRbuRWH96zYC7zA}{eKPutz8vSFqVUwlqw0w2pw}{127.0.0.1}{127.0.0.1:42163}{cdhimrsw}{xpack.installed=true}}, term: 1, version: 1, reason: ApplyCommitRequest{term=1, version=1, sourceNode={node_s1}{NsN10n-yRbuRWH96zYC7zA}{eKPutz8vSFqVUwlqw0w2pw}{127.0.0.1}{127.0.0.1:42163}{cdhimrsw}{xpack.installed=true}}
[2020-11-16T19:39:36,204][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[909]-CLUSTER_SEED=[-5106983454815968100]-HASH=[2F7433B96A7]-cluster[T#1]]] started
[2020-11-16T19:39:36,217][INFO ][o.e.c.s.ClusterApplierService] [node_s1] master node changed {previous [], current [{node_s1}{NsN10n-yRbuRWH96zYC7zA}{eKPutz8vSFqVUwlqw0w2pw}{127.0.0.1}{127.0.0.1:42163}{cdhimrsw}{xpack.installed=true}]}, added {{node_s0}{WlosICA8SIGc2o_vrpJRFw}{qggjhhvURIm1P3Wj6YMTlg}{127.0.0.1}{127.0.0.1:34179}{cdhimrsw}{xpack.installed=true}}, term: 1, version: 1, reason: Publication{term=1, version=1}
[2020-11-16T19:39:36,247][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[909]-CLUSTER_SEED=[-5106983454815968100]-HASH=[2F7433B96A7]-cluster[T#2]]] started
[2020-11-16T19:39:36,287][INFO ][o.e.c.r.a.DiskThresholdMonitor] [node_s1] skipping monitor as a check is already in progress
[2020-11-16T19:39:36,741][INFO ][o.e.g.GatewayService     ] [node_s1] recovered [0] indices into cluster_state
[2020-11-16T19:39:37,406][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s1] adding index template [.watch-history-14] for index patterns [.watcher-history-14*]
[2020-11-16T19:39:37,614][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s1] adding index template [.triggered_watches] for index patterns [.triggered_watches*]
[2020-11-16T19:39:37,739][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s1] adding index template [.watches] for index patterns [.watches*]
[2020-11-16T19:39:37,886][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s1] adding index template [.slm-history] for index patterns [.slm-history-5*]
[2020-11-16T19:39:38,044][INFO ][o.e.x.i.a.TransportPutLifecycleAction] [node_s1] adding index lifecycle policy [watch-history-ilm-policy]
[2020-11-16T19:39:38,222][INFO ][o.e.x.i.a.TransportPutLifecycleAction] [node_s1] adding index lifecycle policy [slm-history-ilm-policy]
[2020-11-16T19:39:38,733][INFO ][o.e.l.LicenseService     ] [node_s0] license [90d88600-371f-4c19-a42d-068f230fbf71] mode [trial] - valid
[2020-11-16T19:39:38,845][INFO ][o.e.l.LicenseService     ] [node_s1] license [90d88600-371f-4c19-a42d-068f230fbf71] mode [trial] - valid
[2020-11-16T19:39:38,893][WARN ][o.e.c.m.MetadataIndexTemplateService] [node_s1] legacy template [random_index_template] has index patterns [*] matching patterns from existing composable templates [.watch-history-14,.triggered_watches,.slm-history,.watches] with patterns (.watch-history-14 => [.watcher-history-14*],.triggered_watches => [.triggered_watches*],.slm-history => [.slm-history-5*],.watches => [.watches*]); this template [random_index_template] may be ignored in favor of a composable template at index creation time
[2020-11-16T19:39:38,895][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s1] adding template [random_index_template] for index patterns [*]
[2020-11-16T19:39:39,038][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] [HistoryActionConditionTests#testActionConditionWithFailures]: all set up test
[2020-11-16T19:39:39,053][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] [HistoryActionConditionTests#testActionConditionWithFailures]: freezing time on nodes
[2020-11-16T19:39:39,066][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] waiting to stop watcher, current states [Tuple [v1=node_s0 (0), v2=STARTED], Tuple [v1=node_s1 (0), v2=STARTED]]
[2020-11-16T19:39:39,220][INFO ][o.e.x.w.WatcherService   ] [node_s0] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
[2020-11-16T19:39:39,222][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s0] watcher has stopped
[2020-11-16T19:39:39,234][INFO ][o.e.x.w.WatcherService   ] [node_s1] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
[2020-11-16T19:39:39,235][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s1] watcher has stopped
[2020-11-16T19:39:39,244][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] waiting to stop watcher, current states [Tuple [v1=node_s0 (0), v2=STOPPED], Tuple [v1=node_s1 (0), v2=STOPPED]]
[2020-11-16T19:39:39,259][DEPRECATION][o.e.d.c.m.MetadataCreateIndexService] [node_s1] data_stream.dataset="deprecation.elasticsearch" data_stream.namespace="default" data_stream.type="logs" ecs.version="1.6" key="index_name_starts_with_dot" message="index name [.watches] starts with a dot '.', in the next major version, index names starting with a dot are reserved for hidden indices and system indices"
[2020-11-16T19:39:39,282][INFO ][o.e.c.m.MetadataCreateIndexService] [node_s1] [.watches] creating index, cause [api], templates [.watches], shards [1]/[0]
[2020-11-16T19:39:39,302][INFO ][o.e.c.r.a.AllocationService] [node_s1] updating number_of_replicas to [1] for indices [.watches]
[2020-11-16T19:39:39,946][DEPRECATION][o.e.d.c.m.MetadataCreateIndexService] [node_s1] data_stream.dataset="deprecation.elasticsearch" data_stream.namespace="default" data_stream.type="logs" ecs.version="1.6" key="index_name_starts_with_dot" message="index name [.triggered_watches] starts with a dot '.', in the next major version, index names starting with a dot are reserved for hidden indices and system indices"
[2020-11-16T19:39:39,984][INFO ][o.e.c.m.MetadataCreateIndexService] [node_s1] [.triggered_watches] creating index, cause [api], templates [.triggered_watches], shards [1]/[1]
[2020-11-16T19:39:40,266][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STOPPED], Tuple [v1=node_s1, v2=STOPPED]]
[2020-11-16T19:39:40,392][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s1, v2=STARTING]]
[2020-11-16T19:39:40,397][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s1, v2=STARTING]]
[2020-11-16T19:39:40,405][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s1, v2=STARTING]]
[2020-11-16T19:39:40,417][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s1, v2=STARTING]]
[2020-11-16T19:39:40,436][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s1, v2=STARTING]]
[2020-11-16T19:39:40,472][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s1, v2=STARTING]]
[2020-11-16T19:39:40,540][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s1, v2=STARTED]]
[2020-11-16T19:39:40,605][INFO ][o.e.c.r.a.AllocationService] [node_s1] current.health="GREEN" message="Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[.watches][0]]])." previous.health="YELLOW" reason="shards started [[.watches][0]]"
[2020-11-16T19:39:40,650][INFO ][o.e.x.w.WatcherService   ] [node_s0] reloading watcher, reason [new local watcher shard allocation ids], cancelled [0] queued tasks
[2020-11-16T19:39:40,668][INFO ][o.e.x.w.WatcherService   ] [node_s1] reloading watcher, reason [new local watcher shard allocation ids], cancelled [0] queued tasks
[2020-11-16T19:39:40,847][INFO ][o.e.x.w.t.ScheduleTriggerEngineMock] [testActionConditionWithFailures] not executing watch [testActionConditionWithFailures] on this scheduler because it is paused
[2020-11-16T19:39:40,848][INFO ][o.e.x.w.t.ScheduleTriggerEngineMock] [testActionConditionWithFailures] not executing watch [testActionConditionWithFailures] on this scheduler because it is paused
[2020-11-16T19:39:40,853][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] [#testActionConditionWithFailures]: clearing watcher state
[2020-11-16T19:39:40,867][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] waiting to stop watcher, current states [Tuple [v1=node_s0 (0), v2=STARTED], Tuple [v1=node_s1 (0), v2=STARTED]]
[2020-11-16T19:39:40,926][INFO ][o.e.x.w.WatcherService   ] [node_s0] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
[2020-11-16T19:39:40,927][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s0] watcher has stopped
[2020-11-16T19:39:40,945][INFO ][o.e.x.w.WatcherService   ] [node_s1] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
[2020-11-16T19:39:40,945][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s1] watcher has stopped
[2020-11-16T19:39:40,958][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] waiting to stop watcher, current states [Tuple [v1=node_s0 (0), v2=STOPPED], Tuple [v1=node_s1 (0), v2=STOPPED]]
[2020-11-16T19:39:40,968][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] [HistoryActionConditionTests#testActionConditionWithFailures]: cleaning up after test
[2020-11-16T19:39:40,969][INFO ][o.e.t.InternalTestCluster] [testActionConditionWithFailures] Clearing active scheme time frozen, expected healing time 0s
[2020-11-16T19:39:41,102][INFO ][o.e.c.m.MetadataDeleteIndexService] [node_s1] [.watches/i4-gfmbySDSackcb-Q05rQ] deleting index
[2020-11-16T19:39:41,103][INFO ][o.e.c.m.MetadataDeleteIndexService] [node_s1] [.triggered_watches/vm5MJ-WtSTq8VaZiLPlhJQ] deleting index
[2020-11-16T19:39:41,300][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s1] removing template [random_index_template]
[2020-11-16T19:39:41,346][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] [HistoryActionConditionTests#testActionConditionWithFailures]: cleaned up after test
[2020-11-16T19:39:41,349][INFO ][o.e.x.w.h.HistoryActionConditionTests] [testActionConditionWithFailures] after test
REPRODUCE WITH: ./gradlew ':x-pack:plugin:watcher:internalClusterTest' --tests "org.elasticsearch.xpack.watcher.history.HistoryActionConditionTests.testActionConditionWithFailures" -Dtests.seed=26E928EADEF031A0 -Dtests.security.manager=true -Dtests.locale=lt -Dtests.timezone=Pacific/Auckland -Druntime.java=11

[elasticmachine]

Pinging @elastic/es-core-features (:Core/Features/Watcher)

[henningandersen]

Had a PR build that failed with a similar failure: https://gradle-enterprise.elastic.co/s/reixtleclqb4u, but did not reproduce with:

./gradlew ':x-pack:plugin:watcher:internalClusterTest' --tests "org.elasticsearch.xpack.watcher.history.HistoryActionConditionTests.testActionConditionWithHardFailures" -Dtests.seed=787226DA992867CC -Dtests.security.manager=true -Dtests.locale=ar-QA -Dtests.timezone=America/St_Lucia -Druntime.java=11

11:38:35 org.elasticsearch.xpack.watcher.history.HistoryActionConditionTests > testActionConditionWithHardFailures FAILED
11:38:35     java.lang.AssertionError: watch was triggered on [0] schedulers, expected [1]
11:38:35     Expected: a value equal to or greater than <1L>
11:38:35          but: <0L> was less than <1L>
11:38:35         at __randomizedtesting.SeedInfo.seed([787226DA992867CC:61213A0E07804D0A]:0)
11:38:35         at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:18)
11:38:35         at org.junit.Assert.assertThat(Assert.java:956)
11:38:35         at org.elasticsearch.xpack.watcher.test.AbstractWatcherIntegrationTestCase$TimeWarp.trigger(AbstractWatcherIntegrationTestCase.java:606)
11:38:35         at org.elasticsearch.xpack.watcher.test.AbstractWatcherIntegrationTestCase$TimeWarp.trigger(AbstractWatcherIntegrationTestCase.java:591)
11:38:35         at org.elasticsearch.xpack.watcher.history.HistoryActionConditionTests.putAndTriggerWatch(HistoryActionConditionTests.java:261)
11:38:35         at org.elasticsearch.xpack.watcher.history.HistoryActionConditionTests.testActionConditionWithHardFailures(HistoryActionConditionTests.java:101)

[probakowski]

@henningandersen did you have latest master merged in? It should be fixed with in #65186

[henningandersen]

The build failure occurred before your fix, thanks for looking into this.

[probakowski]

Ok, I'll close it for now, please reopen if it happens again