search

elastic / elasticsearch

Free and Open Source, Distributed, RESTful Search Engine
https://www.elastic.co/products/elasticsearch
Other
1.19k stars 24.84k forks source link

[CI] ExecutionVarsIntegrationTests.testVars is failing #65086

Closed valeriy42 closed 3 years ago

valeriy42 commented 3 years ago

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

Repro line:

./gradlew ':x-pack:plugin:watcher:internalClusterTest' --tests "org.elasticsearch.xpack.watcher.test.integration.ExecutionVarsIntegrationTests.testVars" -Dtests.seed=6B876C3C963351CB -Dtests.security.manager=true -Dtests.locale=ar-AE -Dtests.timezone=Pacific/Truk -Druntime.java=11

Reproduces locally?: No

Applicable branches: master

Failure history: build stats&_a=(columns:!(_source),index:b646ed00-7efc-11e8-bf69-63c8ef516157,interval:auto,query:(language:lucene,query:'%22ExecutionVarsIntegrationTests%20testVars%22'),sort:!(process.time-start,desc)))

Failure excerpt:

org.elasticsearch.xpack.watcher.test.integration.ExecutionVarsIntegrationTests > testVars FAILED
    java.lang.AssertionError: watch was triggered on [0] schedulers, expected [1]
    Expected: a value equal to or greater than <1L>
         but: <0L> was less than <1L>
        at __randomizedtesting.SeedInfo.seed([6B876C3C963351CB:BFCC74669B86D5C8]:0)
        at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:18)
        at org.junit.Assert.assertThat(Assert.java:956)
        at org.elasticsearch.xpack.watcher.test.AbstractWatcherIntegrationTestCase$TimeWarp.trigger(AbstractWatcherIntegrationTestCase.java:606)
        at org.elasticsearch.xpack.watcher.test.AbstractWatcherIntegrationTestCase$TimeWarp.trigger(AbstractWatcherIntegrationTestCase.java:591)
        at org.elasticsearch.xpack.watcher.test.integration.ExecutionVarsIntegrationTests.testVars(ExecutionVarsIntegrationTests.java:131)
REPRODUCE WITH: ./gradlew ':x-pack:plugin:watcher:internalClusterTest' --tests "org.elasticsearch.xpack.watcher.test.integration.ExecutionVarsIntegrationTests.testVars" -Dtests.seed=6B876C3C963351CB -Dtests.security.manager=true -Dtests.locale=ar-AE -Dtests.timezone=Pacific/Truk -Druntime.java=11

Suite: Test class org.elasticsearch.xpack.watcher.test.integration.ExecutionVarsIntegrationTests
  1> [2020-11-17T00:22:56,892][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] before test
  1> [2020-11-17T00:22:56,911][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] [ExecutionVarsIntegrationTests#testVarsManual]: setting up test
  1> [2020-11-17T00:22:56,989][INFO ][o.e.t.InternalTestCluster] [testVarsManual] Setup InternalTestCluster [SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster] with seed [CE4CBADADA405DDD] using [1] dedicated masters, [3] (data) nodes and [0] coord only nodes (master nodes are [auto-managed])
  1> [2020-11-17T00:22:57,899][INFO ][o.e.n.Node               ] [testVarsManual] version[8.0.0-SNAPSHOT], pid[139975], build[unknown/unknown/923b2b90c5d06ae1a1e26211a1ded65750d2ee58/2020-11-16T14:02:35.834120Z], OS[Linux/5.4.0-1028-gcp/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/11.0.2/11.0.2+7]
  1> [2020-11-17T00:22:57,900][INFO ][o.e.n.Node               ] [testVarsManual] JVM home [/var/lib/jenkins/.java/openjdk-11.0.2-linux]
  1> [2020-11-17T00:22:57,910][DEPRECATION][o.e.d.n.Node             ] [testVarsManual] 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"
  1> [2020-11-17T00:22:57,911][INFO ][o.e.n.Node               ] [testVarsManual] 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=6B876C3C963351CB, -Dtests.task=:x-pack:plugin:watcher:internalClusterTest, --illegal-access=warn, -XX:+HeapDumpOnOutOfMemoryError, -esa, -XX:HeapDumpPath=/dev/shm/elastic+elasticsearch+master+multijob+fast+part2/x-pack/plugin/watcher/build/heapdump, -Xms512m, -Xmx512m, -Dfile.encoding=UTF-8, -Djava.io.tmpdir=/dev/shm/elastic+elasticsearch+master+multijob+fast+part2/x-pack/plugin/watcher/build/testrun/internalClusterTest/temp, -Duser.country=US, -Duser.language=en, -Duser.variant, -ea]
  1> [2020-11-17T00:22:57,912][WARN ][o.e.n.Node               ] [testVarsManual] version [8.0.0-SNAPSHOT] is a pre-release version of Elasticsearch and is not suitable for production
  1> [2020-11-17T00:22:57,947][INFO ][o.e.x.w.t.TimeWarpedWatcher] [testVarsManual] using time warped watchers plugin
  1> [2020-11-17T00:22:57,981][INFO ][o.e.p.PluginsService     ] [testVarsManual] no modules loaded
  1> [2020-11-17T00:22:57,983][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.analysis.common.CommonAnalysisPlugin]
  1> [2020-11-17T00:22:57,984][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.script.MockMustacheScriptEngine$TestPlugin]
  1> [2020-11-17T00:22:57,984][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.script.MockScriptService$TestPlugin]
  1> [2020-11-17T00:22:57,985][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.ESIntegTestCase$AssertActionNamePlugin]
  1> [2020-11-17T00:22:57,985][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
  1> [2020-11-17T00:22:57,986][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.MockHttpTransport$TestPlugin]
  1> [2020-11-17T00:22:57,986][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.TestGeoShapeFieldMapperPlugin]
  1> [2020-11-17T00:22:57,987][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.store.MockFSIndexStore$TestPlugin]
  1> [2020-11-17T00:22:57,987][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
  1> [2020-11-17T00:22:57,988][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.datastreams.DataStreamsPlugin]
  1> [2020-11-17T00:22:57,989][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.ilm.IndexLifecycle]
  1> [2020-11-17T00:22:57,989][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.watcher.test.TimeWarpedWatcher]
  1> [2020-11-17T00:22:57,989][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.watcher.test.integration.ExecutionVarsIntegrationTests$CustomScriptPlugin]
  1> [2020-11-17T00:22:58,083][INFO ][o.e.e.NodeEnvironment    ] [testVarsManual] using [1] data paths, mounts [[/dev/shm (tmpfs)]], net usable_space [44.1gb], net total_space [47.1gb], types [tmpfs]
  1> [2020-11-17T00:22:58,084][INFO ][o.e.e.NodeEnvironment    ] [testVarsManual] heap size [512mb], compressed ordinary object pointers [true]
  1> [2020-11-17T00:22:58,167][INFO ][o.e.n.Node               ] [testVarsManual] node name [node_s0], node ID [7CguAlnHTV-nFWMuwaxa3Q], cluster name [SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster], roles [master, remote_cluster_client, ingest]
  1> [2020-11-17T00:23:03,638][INFO ][o.e.d.DiscoveryModule    ] [testVarsManual] using discovery type [zen] and seed hosts providers [settings, file]
  1> [2020-11-17T00:23:05,069][INFO ][o.e.n.Node               ] [testVarsManual] initialized
  1> [2020-11-17T00:23:05,075][INFO ][o.e.n.Node               ] [testVarsManual] version[8.0.0-SNAPSHOT], pid[139975], build[unknown/unknown/923b2b90c5d06ae1a1e26211a1ded65750d2ee58/2020-11-16T14:02:35.834120Z], OS[Linux/5.4.0-1028-gcp/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/11.0.2/11.0.2+7]
  1> [2020-11-17T00:23:05,075][INFO ][o.e.n.Node               ] [testVarsManual] JVM home [/var/lib/jenkins/.java/openjdk-11.0.2-linux]
  1> [2020-11-17T00:23:05,077][DEPRECATION][o.e.d.n.Node             ] [testVarsManual] 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"
  1> [2020-11-17T00:23:05,096][INFO ][o.e.n.Node               ] [testVarsManual] 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=6B876C3C963351CB, -Dtests.task=:x-pack:plugin:watcher:internalClusterTest, --illegal-access=warn, -XX:+HeapDumpOnOutOfMemoryError, -esa, -XX:HeapDumpPath=/dev/shm/elastic+elasticsearch+master+multijob+fast+part2/x-pack/plugin/watcher/build/heapdump, -Xms512m, -Xmx512m, -Dfile.encoding=UTF-8, -Djava.io.tmpdir=/dev/shm/elastic+elasticsearch+master+multijob+fast+part2/x-pack/plugin/watcher/build/testrun/internalClusterTest/temp, -Duser.country=US, -Duser.language=en, -Duser.variant, -ea]
  1> [2020-11-17T00:23:05,097][WARN ][o.e.n.Node               ] [testVarsManual] version [8.0.0-SNAPSHOT] is a pre-release version of Elasticsearch and is not suitable for production
  1> [2020-11-17T00:23:05,097][INFO ][o.e.x.w.t.TimeWarpedWatcher] [testVarsManual] using time warped watchers plugin
  1> [2020-11-17T00:23:05,098][INFO ][o.e.p.PluginsService     ] [testVarsManual] no modules loaded
  1> [2020-11-17T00:23:05,099][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.analysis.common.CommonAnalysisPlugin]
  1> [2020-11-17T00:23:05,099][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.script.MockMustacheScriptEngine$TestPlugin]
  1> [2020-11-17T00:23:05,099][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.script.MockScriptService$TestPlugin]
  1> [2020-11-17T00:23:05,099][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.ESIntegTestCase$AssertActionNamePlugin]
  1> [2020-11-17T00:23:05,115][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
  1> [2020-11-17T00:23:05,115][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.MockHttpTransport$TestPlugin]
  1> [2020-11-17T00:23:05,115][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.TestGeoShapeFieldMapperPlugin]
  1> [2020-11-17T00:23:05,116][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.store.MockFSIndexStore$TestPlugin]
  1> [2020-11-17T00:23:05,116][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
  1> [2020-11-17T00:23:05,116][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.datastreams.DataStreamsPlugin]
  1> [2020-11-17T00:23:05,116][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.ilm.IndexLifecycle]
  1> [2020-11-17T00:23:05,116][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.watcher.test.TimeWarpedWatcher]
  1> [2020-11-17T00:23:05,117][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.watcher.test.integration.ExecutionVarsIntegrationTests$CustomScriptPlugin]
  1> [2020-11-17T00:23:05,122][INFO ][o.e.e.NodeEnvironment    ] [testVarsManual] using [1] data paths, mounts [[/dev/shm (tmpfs)]], net usable_space [44.1gb], net total_space [47.1gb], types [tmpfs]
  1> [2020-11-17T00:23:05,123][INFO ][o.e.e.NodeEnvironment    ] [testVarsManual] heap size [512mb], compressed ordinary object pointers [true]
  1> [2020-11-17T00:23:05,127][INFO ][o.e.n.Node               ] [testVarsManual] node name [node_s1], node ID [uq8lboudSfm6c8RBnNjhgw], cluster name [SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster], roles [data, remote_cluster_client, ingest]
  1> [2020-11-17T00:23:05,355][INFO ][o.e.d.DiscoveryModule    ] [testVarsManual] using discovery type [zen] and seed hosts providers [settings, file]
  1> [2020-11-17T00:23:05,522][INFO ][o.e.n.Node               ] [testVarsManual] initialized
  1> [2020-11-17T00:23:05,526][INFO ][o.e.n.Node               ] [testVarsManual] version[8.0.0-SNAPSHOT], pid[139975], build[unknown/unknown/923b2b90c5d06ae1a1e26211a1ded65750d2ee58/2020-11-16T14:02:35.834120Z], OS[Linux/5.4.0-1028-gcp/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/11.0.2/11.0.2+7]
  1> [2020-11-17T00:23:05,526][INFO ][o.e.n.Node               ] [testVarsManual] JVM home [/var/lib/jenkins/.java/openjdk-11.0.2-linux]
  1> [2020-11-17T00:23:05,527][DEPRECATION][o.e.d.n.Node             ] [testVarsManual] 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"
  1> [2020-11-17T00:23:05,527][INFO ][o.e.n.Node               ] [testVarsManual] 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=6B876C3C963351CB, -Dtests.task=:x-pack:plugin:watcher:internalClusterTest, --illegal-access=warn, -XX:+HeapDumpOnOutOfMemoryError, -esa, -XX:HeapDumpPath=/dev/shm/elastic+elasticsearch+master+multijob+fast+part2/x-pack/plugin/watcher/build/heapdump, -Xms512m, -Xmx512m, -Dfile.encoding=UTF-8, -Djava.io.tmpdir=/dev/shm/elastic+elasticsearch+master+multijob+fast+part2/x-pack/plugin/watcher/build/testrun/internalClusterTest/temp, -Duser.country=US, -Duser.language=en, -Duser.variant, -ea]
  1> [2020-11-17T00:23:05,528][WARN ][o.e.n.Node               ] [testVarsManual] version [8.0.0-SNAPSHOT] is a pre-release version of Elasticsearch and is not suitable for production
  1> [2020-11-17T00:23:05,529][INFO ][o.e.x.w.t.TimeWarpedWatcher] [testVarsManual] using time warped watchers plugin
  1> [2020-11-17T00:23:05,530][INFO ][o.e.p.PluginsService     ] [testVarsManual] no modules loaded
  1> [2020-11-17T00:23:05,530][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.analysis.common.CommonAnalysisPlugin]
  1> [2020-11-17T00:23:05,530][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.script.MockMustacheScriptEngine$TestPlugin]
  1> [2020-11-17T00:23:05,531][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.script.MockScriptService$TestPlugin]
  1> [2020-11-17T00:23:05,532][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.ESIntegTestCase$AssertActionNamePlugin]
  1> [2020-11-17T00:23:05,547][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
  1> [2020-11-17T00:23:05,547][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.MockHttpTransport$TestPlugin]
  1> [2020-11-17T00:23:05,547][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.TestGeoShapeFieldMapperPlugin]
  1> [2020-11-17T00:23:05,548][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.store.MockFSIndexStore$TestPlugin]
  1> [2020-11-17T00:23:05,548][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
  1> [2020-11-17T00:23:05,548][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.datastreams.DataStreamsPlugin]
  1> [2020-11-17T00:23:05,548][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.ilm.IndexLifecycle]
  1> [2020-11-17T00:23:05,548][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.watcher.test.TimeWarpedWatcher]
  1> [2020-11-17T00:23:05,549][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.watcher.test.integration.ExecutionVarsIntegrationTests$CustomScriptPlugin]
  1> [2020-11-17T00:23:05,553][INFO ][o.e.e.NodeEnvironment    ] [testVarsManual] using [1] data paths, mounts [[/dev/shm (tmpfs)]], net usable_space [44.1gb], net total_space [47.1gb], types [tmpfs]
  1> [2020-11-17T00:23:05,553][INFO ][o.e.e.NodeEnvironment    ] [testVarsManual] heap size [512mb], compressed ordinary object pointers [true]
  1> [2020-11-17T00:23:05,556][INFO ][o.e.n.Node               ] [testVarsManual] node name [node_s2], node ID [TFVuCSeGRsOQw7e8SQ9uWQ], cluster name [SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster], roles [data, remote_cluster_client, ingest]
  1> [2020-11-17T00:23:05,761][INFO ][o.e.d.DiscoveryModule    ] [testVarsManual] using discovery type [zen] and seed hosts providers [settings, file]
  1> [2020-11-17T00:23:05,855][INFO ][o.e.n.Node               ] [testVarsManual] initialized
  1> [2020-11-17T00:23:05,858][INFO ][o.e.n.Node               ] [testVarsManual] version[8.0.0-SNAPSHOT], pid[139975], build[unknown/unknown/923b2b90c5d06ae1a1e26211a1ded65750d2ee58/2020-11-16T14:02:35.834120Z], OS[Linux/5.4.0-1028-gcp/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/11.0.2/11.0.2+7]
  1> [2020-11-17T00:23:05,859][INFO ][o.e.n.Node               ] [testVarsManual] JVM home [/var/lib/jenkins/.java/openjdk-11.0.2-linux]
  1> [2020-11-17T00:23:05,860][DEPRECATION][o.e.d.n.Node             ] [testVarsManual] 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"
  1> [2020-11-17T00:23:05,861][INFO ][o.e.n.Node               ] [testVarsManual] 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=6B876C3C963351CB, -Dtests.task=:x-pack:plugin:watcher:internalClusterTest, --illegal-access=warn, -XX:+HeapDumpOnOutOfMemoryError, -esa, -XX:HeapDumpPath=/dev/shm/elastic+elasticsearch+master+multijob+fast+part2/x-pack/plugin/watcher/build/heapdump, -Xms512m, -Xmx512m, -Dfile.encoding=UTF-8, -Djava.io.tmpdir=/dev/shm/elastic+elasticsearch+master+multijob+fast+part2/x-pack/plugin/watcher/build/testrun/internalClusterTest/temp, -Duser.country=US, -Duser.language=en, -Duser.variant, -ea]
  1> [2020-11-17T00:23:05,862][WARN ][o.e.n.Node               ] [testVarsManual] version [8.0.0-SNAPSHOT] is a pre-release version of Elasticsearch and is not suitable for production
  1> [2020-11-17T00:23:05,863][INFO ][o.e.x.w.t.TimeWarpedWatcher] [testVarsManual] using time warped watchers plugin
  1> [2020-11-17T00:23:05,867][INFO ][o.e.p.PluginsService     ] [testVarsManual] no modules loaded
  1> [2020-11-17T00:23:05,869][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.analysis.common.CommonAnalysisPlugin]
  1> [2020-11-17T00:23:05,871][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.script.MockMustacheScriptEngine$TestPlugin]
  1> [2020-11-17T00:23:05,874][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.script.MockScriptService$TestPlugin]
  1> [2020-11-17T00:23:05,875][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.ESIntegTestCase$AssertActionNamePlugin]
  1> [2020-11-17T00:23:05,875][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
  1> [2020-11-17T00:23:05,877][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.MockHttpTransport$TestPlugin]
  1> [2020-11-17T00:23:05,878][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.TestGeoShapeFieldMapperPlugin]
  1> [2020-11-17T00:23:05,878][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.test.store.MockFSIndexStore$TestPlugin]
  1> [2020-11-17T00:23:05,879][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
  1> [2020-11-17T00:23:05,879][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.datastreams.DataStreamsPlugin]
  1> [2020-11-17T00:23:05,879][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.ilm.IndexLifecycle]
  1> [2020-11-17T00:23:05,879][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.watcher.test.TimeWarpedWatcher]
  1> [2020-11-17T00:23:05,879][INFO ][o.e.p.PluginsService     ] [testVarsManual] loaded plugin [org.elasticsearch.xpack.watcher.test.integration.ExecutionVarsIntegrationTests$CustomScriptPlugin]
  1> [2020-11-17T00:23:05,885][INFO ][o.e.e.NodeEnvironment    ] [testVarsManual] using [1] data paths, mounts [[/dev/shm (tmpfs)]], net usable_space [44.1gb], net total_space [47.1gb], types [tmpfs]
  1> [2020-11-17T00:23:05,886][INFO ][o.e.e.NodeEnvironment    ] [testVarsManual] heap size [512mb], compressed ordinary object pointers [true]
  1> [2020-11-17T00:23:05,892][INFO ][o.e.n.Node               ] [testVarsManual] node name [node_s3], node ID [YzpDD7oRRVK0GFwlx3-Vew], cluster name [SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster], roles [data, remote_cluster_client, ingest]
  1> [2020-11-17T00:23:06,105][INFO ][o.e.d.DiscoveryModule    ] [testVarsManual] using discovery type [zen] and seed hosts providers [settings, file]
  1> [2020-11-17T00:23:06,241][INFO ][o.e.n.Node               ] [testVarsManual] initialized
  1> [2020-11-17T00:23:06,263][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster[T#1]]] starting ...
  1> [2020-11-17T00:23:06,284][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster[T#2]]] starting ...
  1> [2020-11-17T00:23:06,287][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster[T#3]]] starting ...
  1> [2020-11-17T00:23:06,295][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster[T#4]]] starting ...
  1> [2020-11-17T00:23:06,544][INFO ][o.e.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster[T#4]]] publish_address {127.0.0.1:45269}, bound_addresses {[::1]:33831}, {127.0.0.1:45269}
  1> [2020-11-17T00:23:06,544][INFO ][o.e.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster[T#3]]] publish_address {127.0.0.1:42469}, bound_addresses {[::1]:38223}, {127.0.0.1:42469}
  1> [2020-11-17T00:23:06,564][INFO ][o.e.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster[T#1]]] publish_address {127.0.0.1:43047}, bound_addresses {[::1]:35243}, {127.0.0.1:43047}
  1> [2020-11-17T00:23:06,579][INFO ][o.e.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster[T#2]]] publish_address {127.0.0.1:33507}, bound_addresses {[::1]:35527}, {127.0.0.1:33507}
  1> [2020-11-17T00:23:07,275][INFO ][o.e.c.c.Coordinator      ] [[test_SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster[T#1]]] setting initial configuration to VotingConfiguration{7CguAlnHTV-nFWMuwaxa3Q}
  1> [2020-11-17T00:23:07,904][INFO ][o.e.c.s.MasterService    ] [node_s0] elected-as-master ([1] nodes joined)[{node_s0}{7CguAlnHTV-nFWMuwaxa3Q}{3QyrCFI_TQOCfE2dQ-8S9Q}{127.0.0.1}{127.0.0.1:43047}{imr}{xpack.installed=true} elect leader, _BECOME_MASTER_TASK_, _FINISH_ELECTION_], term: 1, version: 1, delta: master node changed {previous [], current [{node_s0}{7CguAlnHTV-nFWMuwaxa3Q}{3QyrCFI_TQOCfE2dQ-8S9Q}{127.0.0.1}{127.0.0.1:43047}{imr}{xpack.installed=true}]}
  1> [2020-11-17T00:23:08,059][INFO ][o.e.c.c.CoordinationState] [node_s0] cluster UUID set to [SV-hyV48R52ZoSB2BKMf0g]
  1> [2020-11-17T00:23:08,147][INFO ][o.e.c.s.ClusterApplierService] [node_s0] master node changed {previous [], current [{node_s0}{7CguAlnHTV-nFWMuwaxa3Q}{3QyrCFI_TQOCfE2dQ-8S9Q}{127.0.0.1}{127.0.0.1:43047}{imr}{xpack.installed=true}]}, term: 1, version: 1, reason: Publication{term=1, version=1}
  1> [2020-11-17T00:23:08,240][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster[T#1]]] started
  1> [2020-11-17T00:23:08,619][INFO ][o.e.g.GatewayService     ] [node_s0] recovered [0] indices into cluster_state
  1> [2020-11-17T00:23:08,624][INFO ][o.e.c.s.MasterService    ] [node_s0] node-join[{node_s3}{YzpDD7oRRVK0GFwlx3-Vew}{wWDGh_HhSRKOqAunMptCXA}{127.0.0.1}{127.0.0.1:45269}{dir}{xpack.installed=true} join existing leader, {node_s1}{uq8lboudSfm6c8RBnNjhgw}{7Lrpk5hDSQGGyzFxDur57g}{127.0.0.1}{127.0.0.1:33507}{dir}{xpack.installed=true} join existing leader, {node_s2}{TFVuCSeGRsOQw7e8SQ9uWQ}{ckoBbM5ERk6gJ8CerlIJEA}{127.0.0.1}{127.0.0.1:42469}{dir}{xpack.installed=true} join existing leader], term: 1, version: 3, delta: added {{node_s2}{TFVuCSeGRsOQw7e8SQ9uWQ}{ckoBbM5ERk6gJ8CerlIJEA}{127.0.0.1}{127.0.0.1:42469}{dir}{xpack.installed=true},{node_s1}{uq8lboudSfm6c8RBnNjhgw}{7Lrpk5hDSQGGyzFxDur57g}{127.0.0.1}{127.0.0.1:33507}{dir}{xpack.installed=true},{node_s3}{YzpDD7oRRVK0GFwlx3-Vew}{wWDGh_HhSRKOqAunMptCXA}{127.0.0.1}{127.0.0.1:45269}{dir}{xpack.installed=true}}
  1> [2020-11-17T00:23:08,761][INFO ][o.e.c.s.ClusterApplierService] [node_s1] master node changed {previous [], current [{node_s0}{7CguAlnHTV-nFWMuwaxa3Q}{3QyrCFI_TQOCfE2dQ-8S9Q}{127.0.0.1}{127.0.0.1:43047}{imr}{xpack.installed=true}]}, added {{node_s0}{7CguAlnHTV-nFWMuwaxa3Q}{3QyrCFI_TQOCfE2dQ-8S9Q}{127.0.0.1}{127.0.0.1:43047}{imr}{xpack.installed=true},{node_s2}{TFVuCSeGRsOQw7e8SQ9uWQ}{ckoBbM5ERk6gJ8CerlIJEA}{127.0.0.1}{127.0.0.1:42469}{dir}{xpack.installed=true},{node_s3}{YzpDD7oRRVK0GFwlx3-Vew}{wWDGh_HhSRKOqAunMptCXA}{127.0.0.1}{127.0.0.1:45269}{dir}{xpack.installed=true}}, term: 1, version: 3, reason: ApplyCommitRequest{term=1, version=3, sourceNode={node_s0}{7CguAlnHTV-nFWMuwaxa3Q}{3QyrCFI_TQOCfE2dQ-8S9Q}{127.0.0.1}{127.0.0.1:43047}{imr}{xpack.installed=true}}
  1> [2020-11-17T00:23:08,762][INFO ][o.e.c.s.ClusterApplierService] [node_s2] master node changed {previous [], current [{node_s0}{7CguAlnHTV-nFWMuwaxa3Q}{3QyrCFI_TQOCfE2dQ-8S9Q}{127.0.0.1}{127.0.0.1:43047}{imr}{xpack.installed=true}]}, added {{node_s0}{7CguAlnHTV-nFWMuwaxa3Q}{3QyrCFI_TQOCfE2dQ-8S9Q}{127.0.0.1}{127.0.0.1:43047}{imr}{xpack.installed=true},{node_s1}{uq8lboudSfm6c8RBnNjhgw}{7Lrpk5hDSQGGyzFxDur57g}{127.0.0.1}{127.0.0.1:33507}{dir}{xpack.installed=true},{node_s3}{YzpDD7oRRVK0GFwlx3-Vew}{wWDGh_HhSRKOqAunMptCXA}{127.0.0.1}{127.0.0.1:45269}{dir}{xpack.installed=true}}, term: 1, version: 3, reason: ApplyCommitRequest{term=1, version=3, sourceNode={node_s0}{7CguAlnHTV-nFWMuwaxa3Q}{3QyrCFI_TQOCfE2dQ-8S9Q}{127.0.0.1}{127.0.0.1:43047}{imr}{xpack.installed=true}}
  1> [2020-11-17T00:23:08,767][INFO ][o.e.c.s.ClusterApplierService] [node_s3] master node changed {previous [], current [{node_s0}{7CguAlnHTV-nFWMuwaxa3Q}{3QyrCFI_TQOCfE2dQ-8S9Q}{127.0.0.1}{127.0.0.1:43047}{imr}{xpack.installed=true}]}, added {{node_s0}{7CguAlnHTV-nFWMuwaxa3Q}{3QyrCFI_TQOCfE2dQ-8S9Q}{127.0.0.1}{127.0.0.1:43047}{imr}{xpack.installed=true},{node_s2}{TFVuCSeGRsOQw7e8SQ9uWQ}{ckoBbM5ERk6gJ8CerlIJEA}{127.0.0.1}{127.0.0.1:42469}{dir}{xpack.installed=true},{node_s1}{uq8lboudSfm6c8RBnNjhgw}{7Lrpk5hDSQGGyzFxDur57g}{127.0.0.1}{127.0.0.1:33507}{dir}{xpack.installed=true}}, term: 1, version: 3, reason: ApplyCommitRequest{term=1, version=3, sourceNode={node_s0}{7CguAlnHTV-nFWMuwaxa3Q}{3QyrCFI_TQOCfE2dQ-8S9Q}{127.0.0.1}{127.0.0.1:43047}{imr}{xpack.installed=true}}
  1> [2020-11-17T00:23:08,840][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster[T#3]]] started
  1> [2020-11-17T00:23:08,841][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster[T#2]]] started
  1> [2020-11-17T00:23:08,842][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[537]-CLUSTER_SEED=[-3581282154539098659]-HASH=[1309DA1142A]-cluster[T#4]]] started
  1> [2020-11-17T00:23:08,848][INFO ][o.e.c.s.ClusterApplierService] [node_s0] added {{node_s2}{TFVuCSeGRsOQw7e8SQ9uWQ}{ckoBbM5ERk6gJ8CerlIJEA}{127.0.0.1}{127.0.0.1:42469}{dir}{xpack.installed=true},{node_s1}{uq8lboudSfm6c8RBnNjhgw}{7Lrpk5hDSQGGyzFxDur57g}{127.0.0.1}{127.0.0.1:33507}{dir}{xpack.installed=true},{node_s3}{YzpDD7oRRVK0GFwlx3-Vew}{wWDGh_HhSRKOqAunMptCXA}{127.0.0.1}{127.0.0.1:45269}{dir}{xpack.installed=true}}, term: 1, version: 3, reason: Publication{term=1, version=3}
  1> [2020-11-17T00:23:09,867][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s0] adding index template [.triggered_watches] for index patterns [.triggered_watches*]
  1> [2020-11-17T00:23:10,194][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s0] adding index template [.watch-history-14] for index patterns [.watcher-history-14*]
  1> [2020-11-17T00:23:10,381][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s0] adding index template [.watches] for index patterns [.watches*]
  1> [2020-11-17T00:23:10,584][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s0] adding index template [.slm-history] for index patterns [.slm-history-5*]
  1> [2020-11-17T00:23:10,677][INFO ][o.e.x.i.a.TransportPutLifecycleAction] [node_s0] adding index lifecycle policy [watch-history-ilm-policy]
  1> [2020-11-17T00:23:10,854][INFO ][o.e.x.i.a.TransportPutLifecycleAction] [node_s0] adding index lifecycle policy [slm-history-ilm-policy]
  1> [2020-11-17T00:23:11,461][INFO ][o.e.l.LicenseService     ] [node_s1] license [79a94ba5-7aa0-485f-bcfb-2d91ba528a2c] mode [trial] - valid
  1> [2020-11-17T00:23:11,503][INFO ][o.e.l.LicenseService     ] [node_s2] license [79a94ba5-7aa0-485f-bcfb-2d91ba528a2c] mode [trial] - valid
  1> [2020-11-17T00:23:11,543][INFO ][o.e.l.LicenseService     ] [node_s3] license [79a94ba5-7aa0-485f-bcfb-2d91ba528a2c] mode [trial] - valid
  1> [2020-11-17T00:23:11,680][INFO ][o.e.l.LicenseService     ] [node_s0] license [79a94ba5-7aa0-485f-bcfb-2d91ba528a2c] mode [trial] - valid
  1> [2020-11-17T00:23:11,733][WARN ][o.e.c.m.MetadataIndexTemplateService] [node_s0] legacy template [random_index_template] has index patterns [*] matching patterns from existing composable templates [.triggered_watches,.watch-history-14,.slm-history,.watches] with patterns (.triggered_watches => [.triggered_watches*],.watch-history-14 => [.watcher-history-14*],.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
  1> [2020-11-17T00:23:11,734][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s0] adding template [random_index_template] for index patterns [*]
  1> [2020-11-17T00:23:11,814][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] [ExecutionVarsIntegrationTests#testVarsManual]: all set up test
  1> [2020-11-17T00:23:11,826][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] [ExecutionVarsIntegrationTests#testVarsManual]: freezing time on nodes
  1> [2020-11-17T00:23:11,849][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] waiting to stop watcher, current states [Tuple [v1=node_s0 (0), v2=STARTED], Tuple [v1=node_s2 (0), v2=STARTED], Tuple [v1=node_s1 (0), v2=STARTED], Tuple [v1=node_s3 (0), v2=STARTED]]
  1> [2020-11-17T00:23:11,941][INFO ][o.e.x.w.WatcherService   ] [node_s2] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-17T00:23:11,942][INFO ][o.e.x.w.WatcherService   ] [node_s3] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-17T00:23:11,943][INFO ][o.e.x.w.WatcherService   ] [node_s1] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-17T00:23:11,943][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s3] watcher has stopped
  1> [2020-11-17T00:23:11,944][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s1] watcher has stopped
  1> [2020-11-17T00:23:11,943][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s2] watcher has stopped
  1> [2020-11-17T00:23:11,955][INFO ][o.e.x.w.WatcherService   ] [node_s0] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-17T00:23:11,956][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s0] watcher has stopped
  1> [2020-11-17T00:23:11,973][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] waiting to stop watcher, current states [Tuple [v1=node_s0 (0), v2=STOPPED], Tuple [v1=node_s2 (0), v2=STOPPED], Tuple [v1=node_s1 (0), v2=STOPPED], Tuple [v1=node_s3 (0), v2=STOPPED]]
  1> [2020-11-17T00:23:11,989][DEPRECATION][o.e.d.c.m.MetadataCreateIndexService] [node_s0] 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 [.watchesptbvw] starts with a dot '.', in the next major version, index names starting with a dot are reserved for hidden indices and system indices"
  1> [2020-11-17T00:23:12,050][INFO ][o.e.c.m.MetadataCreateIndexService] [node_s0] [.watchesptbvw] creating index, cause [Index to test aliases with .watches index], templates [.watches], shards [1]/[0]
  1> [2020-11-17T00:23:12,084][INFO ][o.e.c.r.a.AllocationService] [node_s0] updating number_of_replicas to [1] for indices [.watchesptbvw]
  1> [2020-11-17T00:23:13,131][INFO ][o.e.c.m.MetadataCreateIndexService] [node_s0] [rxetwnwf] creating index, cause [api], templates [random_index_template], shards [1]/[1]
  1> [2020-11-17T00:23:13,920][INFO ][o.e.c.r.a.AllocationService] [node_s0] current.health="GREEN" message="Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[.watchesptbvw][0]]])." previous.health="YELLOW" reason="shards started [[.watchesptbvw][0]]"
  1> [2020-11-17T00:23:13,995][INFO ][o.e.c.m.MetadataDeleteIndexService] [node_s0] [.watchesptbvw/KTSqLxaySz-s176I_FEHxw] deleting index
  1> [2020-11-17T00:23:14,290][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] set alias for .watches index to [rxetwnwf]
  1> [2020-11-17T00:23:14,319][DEPRECATION][o.e.d.c.m.MetadataCreateIndexService] [node_s0] 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-alias-index] starts with a dot '.', in the next major version, index names starting with a dot are reserved for hidden indices and system indices"
  1> [2020-11-17T00:23:14,334][INFO ][o.e.c.m.MetadataCreateIndexService] [node_s0] [.triggered_watches-alias-index] creating index, cause [Index to test aliases with .triggered-watches index], templates [.triggered_watches], shards [1]/[1]
  1> [2020-11-17T00:23:14,593][INFO ][o.e.c.m.MetadataCreateIndexService] [node_s0] [szxqkci] creating index, cause [api], templates [random_index_template], shards [1]/[1]
  1> [2020-11-17T00:23:15,262][INFO ][o.e.c.r.a.AllocationService] [node_s0] current.health="GREEN" message="Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[szxqkci][0]]])." previous.health="YELLOW" reason="shards started [[szxqkci][0]]"
  1> [2020-11-17T00:23:15,325][INFO ][o.e.c.m.MetadataDeleteIndexService] [node_s0] [.triggered_watches-alias-index/v5ZC0qjRTQuQmSABOtSOXQ] deleting index
  1> [2020-11-17T00:23:15,586][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] set alias for .triggered-watches index to [szxqkci]
  1> [2020-11-17T00:23:15,591][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STOPPED], Tuple [v1=node_s2, v2=STOPPED], Tuple [v1=node_s1, v2=STOPPED], Tuple [v1=node_s3, v2=STOPPED]]
  1> [2020-11-17T00:23:15,705][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTING], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTING]]
  1> [2020-11-17T00:23:15,711][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTING], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTING]]
  1> [2020-11-17T00:23:15,718][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTING], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTING]]
  1> [2020-11-17T00:23:15,733][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTING]]
  1> [2020-11-17T00:23:15,756][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTING]]
  1> [2020-11-17T00:23:15,797][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTING]]
  1> [2020-11-17T00:23:15,888][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTING]]
  1> [2020-11-17T00:23:16,020][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s2, v2=STARTED], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTED]]
  1> [2020-11-17T00:23:16,441][INFO ][o.e.x.w.a.l.ExecutableLoggingAction] [node_s3] _text
  1> [2020-11-17T00:23:16,445][INFO ][o.e.x.w.a.l.ExecutableLoggingAction] [node_s3] _text
  1> [2020-11-17T00:23:16,520][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] [#testVarsManual]: clearing watcher state
  1> [2020-11-17T00:23:16,522][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] waiting to stop watcher, current states [Tuple [v1=node_s0 (0), v2=STARTED], Tuple [v1=node_s2 (0), v2=STARTED], Tuple [v1=node_s1 (0), v2=STARTED], Tuple [v1=node_s3 (0), v2=STARTED]]
  1> [2020-11-17T00:23:16,564][INFO ][o.e.x.w.WatcherService   ] [node_s1] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-17T00:23:16,564][INFO ][o.e.x.w.WatcherService   ] [node_s2] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-17T00:23:16,564][INFO ][o.e.x.w.WatcherService   ] [node_s3] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-17T00:23:16,564][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s1] watcher has stopped
  1> [2020-11-17T00:23:16,565][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s2] watcher has stopped
  1> [2020-11-17T00:23:16,570][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s3] watcher has stopped
  1> [2020-11-17T00:23:16,579][INFO ][o.e.x.w.WatcherService   ] [node_s0] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-17T00:23:16,580][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s0] watcher has stopped
  1> [2020-11-17T00:23:16,608][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] waiting to stop watcher, current states [Tuple [v1=node_s0 (0), v2=STOPPED], Tuple [v1=node_s2 (0), v2=STOPPED], Tuple [v1=node_s1 (0), v2=STOPPED], Tuple [v1=node_s3 (0), v2=STOPPED]]
  1> [2020-11-17T00:23:16,647][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] [ExecutionVarsIntegrationTests#testVarsManual]: cleaning up after test
  1> [2020-11-17T00:23:16,647][INFO ][o.e.t.InternalTestCluster] [testVarsManual] Clearing active scheme time frozen, expected healing time 0s
  1> [2020-11-17T00:23:16,962][INFO ][o.e.c.m.MetadataDeleteIndexService] [node_s0] [rxetwnwf/AmuHMtYlTG2o-_zPzNZFSQ] deleting index
  1> [2020-11-17T00:23:16,962][INFO ][o.e.c.m.MetadataDeleteIndexService] [node_s0] [szxqkci/jpg3xWe3TeqIazb__3D4jQ] deleting index
  1> [2020-11-17T00:23:17,086][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s0] removing template [random_index_template]
  1> [2020-11-17T00:23:17,167][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] [ExecutionVarsIntegrationTests#testVarsManual]: cleaned up after test
  1> [2020-11-17T00:23:17,170][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVarsManual] after test
  1> [2020-11-17T00:23:17,262][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] before test
  1> [2020-11-17T00:23:17,267][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] [ExecutionVarsIntegrationTests#testVars]: setting up test
  1> [2020-11-17T00:23:17,290][WARN ][o.e.c.m.MetadataIndexTemplateService] [node_s0] legacy template [random_index_template] has index patterns [*] matching patterns from existing composable templates [.triggered_watches,.watch-history-14,.slm-history,.watches] with patterns (.triggered_watches => [.triggered_watches*],.watch-history-14 => [.watcher-history-14*],.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
  1> [2020-11-17T00:23:17,291][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s0] adding template [random_index_template] for index patterns [*]
  1> [2020-11-17T00:23:17,344][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] [ExecutionVarsIntegrationTests#testVars]: all set up test
  1> [2020-11-17T00:23:17,348][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] [ExecutionVarsIntegrationTests#testVars]: freezing time on nodes
  1> [2020-11-17T00:23:17,353][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] waiting to stop watcher, current states [Tuple [v1=node_s0 (0), v2=STOPPED], Tuple [v1=node_s2 (0), v2=STOPPED], Tuple [v1=node_s1 (0), v2=STOPPED], Tuple [v1=node_s3 (0), v2=STOPPED]]
  1> [2020-11-17T00:23:17,357][DEPRECATION][o.e.d.c.m.MetadataCreateIndexService] [node_s0] 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"
  1> [2020-11-17T00:23:17,365][INFO ][o.e.c.m.MetadataCreateIndexService] [node_s0] [.watches] creating index, cause [api], templates [.watches], shards [1]/[0]
  1> [2020-11-17T00:23:17,374][INFO ][o.e.c.r.a.AllocationService] [node_s0] updating number_of_replicas to [1] for indices [.watches]
  1> [2020-11-17T00:23:17,662][DEPRECATION][o.e.d.c.m.MetadataCreateIndexService] [node_s0] 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"
  1> [2020-11-17T00:23:17,673][INFO ][o.e.c.m.MetadataCreateIndexService] [node_s0] [.triggered_watches] creating index, cause [api], templates [.triggered_watches], shards [1]/[1]
  1> [2020-11-17T00:23:18,054][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STOPPED], Tuple [v1=node_s2, v2=STOPPED], Tuple [v1=node_s1, v2=STOPPED], Tuple [v1=node_s3, v2=STOPPED]]
  1> [2020-11-17T00:23:18,171][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTED]]
  1> [2020-11-17T00:23:18,207][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTED]]
  1> [2020-11-17T00:23:18,213][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTED]]
  1> [2020-11-17T00:23:18,224][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTED]]
  1> [2020-11-17T00:23:18,234][INFO ][o.e.x.w.WatcherService   ] [node_s1] reloading watcher, reason [new local watcher shard allocation ids], cancelled [0] queued tasks
  1> [2020-11-17T00:23:18,242][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTED]]
  1> [2020-11-17T00:23:18,278][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s2, v2=STARTED], Tuple [v1=node_s1, v2=STARTED], Tuple [v1=node_s3, v2=STARTED]]
  1> [2020-11-17T00:23:18,513][INFO ][o.e.x.w.t.ScheduleTriggerEngineMock] [testVars] not executing watch [sxrSlLiftaevxzFKiooF] on this scheduler because it is paused
  1> [2020-11-17T00:23:18,516][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] [#testVars]: clearing watcher state
  1> [2020-11-17T00:23:18,521][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] waiting to stop watcher, current states [Tuple [v1=node_s0 (0), v2=STARTED], Tuple [v1=node_s2 (0), v2=STARTED], Tuple [v1=node_s1 (0), v2=STARTED], Tuple [v1=node_s3 (0), v2=STARTED]]
  1> [2020-11-17T00:23:18,578][INFO ][o.e.x.w.WatcherService   ] [node_s3] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-17T00:23:18,578][INFO ][o.e.x.w.WatcherService   ] [node_s2] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-17T00:23:18,579][INFO ][o.e.x.w.WatcherService   ] [node_s1] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-17T00:23:18,579][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s3] watcher has stopped
  1> [2020-11-17T00:23:18,579][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s1] watcher has stopped
  1> [2020-11-17T00:23:18,581][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s2] watcher has stopped
  1> [2020-11-17T00:23:18,586][INFO ][o.e.x.w.WatcherService   ] [node_s0] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-17T00:23:18,587][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s0] watcher has stopped
  1> [2020-11-17T00:23:18,595][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] waiting to stop watcher, current states [Tuple [v1=node_s0 (0), v2=STOPPED], Tuple [v1=node_s2 (0), v2=STOPPED], Tuple [v1=node_s1 (0), v2=STOPPED], Tuple [v1=node_s3 (0), v2=STOPPED]]
  1> [2020-11-17T00:23:18,596][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] [ExecutionVarsIntegrationTests#testVars]: cleaning up after test
  1> [2020-11-17T00:23:18,597][INFO ][o.e.t.InternalTestCluster] [testVars] Clearing active scheme time frozen, expected healing time 0s
  1> [2020-11-17T00:23:18,727][INFO ][o.e.c.r.a.AllocationService] [node_s0] current.health="GREEN" message="Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[.triggered_watches][0]]])." previous.health="YELLOW" reason="shards started [[.triggered_watches][0]]"
  1> [2020-11-17T00:23:18,895][INFO ][o.e.c.m.MetadataDeleteIndexService] [node_s0] [.triggered_watches/BN3IQb9HQ827vDtn7_JlEg] deleting index
  1> [2020-11-17T00:23:18,895][INFO ][o.e.c.m.MetadataDeleteIndexService] [node_s0] [.watches/rsrtJEuAQmqQ9t8XwUw_Xg] deleting index
  1> [2020-11-17T00:23:19,070][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s0] removing template [random_index_template]
  1> [2020-11-17T00:23:19,110][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] [ExecutionVarsIntegrationTests#testVars]: cleaned up after test
  1> [2020-11-17T00:23:19,112][INFO ][o.e.x.w.t.i.ExecutionVarsIntegrationTests] [testVars] after test
  2> REPRODUCE WITH: ./gradlew ':x-pack:plugin:watcher:internalClusterTest' --tests "org.elasticsearch.xpack.watcher.test.integration.ExecutionVarsIntegrationTests.testVars" -Dtests.seed=6B876C3C963351CB -Dtests.security.manager=true -Dtests.locale=ar-AE
elasticmachine commented 3 years ago

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

probakowski commented 3 years ago

Should be fixed by #65186