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] HistoryTemplateTimeMappingsTests.testTimeFields is failing #65089

Closed valeriy42 closed 3 years ago

valeriy42 commented 3 years ago

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

Repro line:

./gradlew ':x-pack:plugin:watcher:internalClusterTest' --tests "org.elasticsearch.xpack.watcher.history.HistoryTemplateTimeMappingsTests.testTimeFields" -Dtests.seed=D45BD2113B5CEAE2 -Dtests.security.manager=true -Dtests.locale=tr -Dtests.timezone=America/North_Dakota/New_Salem -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:'%22HistoryTemplateTimeMappingsTests%20testTimeFields%22'),sort:!(process.time-start,desc)))

Failure excerpt:

org.elasticsearch.xpack.watcher.history.HistoryTemplateTimeMappingsTests > testTimeFields 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([D45BD2113B5CEAE2:C14F425CBF9E6728]: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.history.HistoryTemplateTimeMappingsTests.testTimeFields(HistoryTemplateTimeMappingsTests.java:44)
REPRODUCE WITH: ./gradlew ':x-pack:plugin:watcher:internalClusterTest' --tests "org.elasticsearch.xpack.watcher.history.HistoryTemplateTimeMappingsTests.testTimeFields" -Dtests.seed=D45BD2113B5CEAE2 -Dtests.security.manager=true -Dtests.locale=tr -Dtests.timezone=America/North_Dakota/New_Salem -Druntime.java=11

Suite: Test class org.elasticsearch.xpack.watcher.history.HistoryTemplateTimeMappingsTests
  1> [2020-11-16T08:00:05,268][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] before test
  1> [2020-11-16T08:00:05,283][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] [HistoryTemplateTimeMappingsTests#testTimeFields]: setting up test
  1> [2020-11-16T08:00:05,284][INFO ][o.e.t.InternalTestCluster] [testTimeFields] Setup InternalTestCluster [SUITE-TEST_WORKER_VM=[12]-CLUSTER_SEED=[4533184138362207540]-HASH=[26977DF3EC]-cluster] with seed [3EE91AF4BC83BD34] using [0] dedicated masters, [3] (data) nodes and [0] coord only nodes (master nodes are [auto-managed])
  1> [2020-11-16T08:00:05,296][INFO ][o.e.n.Node               ] [testTimeFields] version[8.0.0-SNAPSHOT], pid[5741], build[unknown/unknown/0a2891e1e2662d34235b92d3e86977c2d42146c2/2020-11-16T13:58:40.647513Z], OS[Linux/4.15.0-1086-gcp/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/11.0.2/11.0.2+7]
  1> [2020-11-16T08:00:05,302][INFO ][o.e.n.Node               ] [testTimeFields] JVM home [/var/lib/jenkins/.java/openjdk-11.0.2-linux]
  1> [2020-11-16T08:00:05,303][DEPRECATION][o.e.d.n.Node             ] [testTimeFields] 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-16T08:00:05,304][INFO ][o.e.n.Node               ] [testTimeFields] 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=D45BD2113B5CEAE2, -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-16T08:00:05,307][WARN ][o.e.n.Node               ] [testTimeFields] version [8.0.0-SNAPSHOT] is a pre-release version of Elasticsearch and is not suitable for production
  1> [2020-11-16T08:00:05,308][INFO ][o.e.x.w.t.TimeWarpedWatcher] [testTimeFields] using time warped watchers plugin
  1> [2020-11-16T08:00:05,308][INFO ][o.e.p.PluginsService     ] [testTimeFields] no modules loaded
  1> [2020-11-16T08:00:05,309][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.analysis.common.CommonAnalysisPlugin]
  1> [2020-11-16T08:00:05,316][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.script.MockMustacheScriptEngine$TestPlugin]
  1> [2020-11-16T08:00:05,317][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.script.MockScriptService$TestPlugin]
  1> [2020-11-16T08:00:05,319][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.ESIntegTestCase$AssertActionNamePlugin]
  1> [2020-11-16T08:00:05,320][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
  1> [2020-11-16T08:00:05,320][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.MockHttpTransport$TestPlugin]
  1> [2020-11-16T08:00:05,321][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.TestGeoShapeFieldMapperPlugin]
  1> [2020-11-16T08:00:05,321][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.store.MockFSIndexStore$TestPlugin]
  1> [2020-11-16T08:00:05,322][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
  1> [2020-11-16T08:00:05,322][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.xpack.datastreams.DataStreamsPlugin]
  1> [2020-11-16T08:00:05,322][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.xpack.ilm.IndexLifecycle]
  1> [2020-11-16T08:00:05,323][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.xpack.watcher.test.TimeWarpedWatcher]
  1> [2020-11-16T08:00:05,328][INFO ][o.e.e.NodeEnvironment    ] [testTimeFields] using [1] data paths, mounts [[/dev/shm (tmpfs)]], net usable_space [44.1gb], net total_space [47.2gb], types [tmpfs]
  1> [2020-11-16T08:00:05,328][INFO ][o.e.e.NodeEnvironment    ] [testTimeFields] heap size [512mb], compressed ordinary object pointers [true]
  1> [2020-11-16T08:00:05,333][INFO ][o.e.n.Node               ] [testTimeFields] node name [node_s0], node ID [YO4C_IYjQK-ZGcRknbg2oQ], cluster name [SUITE-TEST_WORKER_VM=[12]-CLUSTER_SEED=[4533184138362207540]-HASH=[26977DF3EC]-cluster], roles [ingest, data_content, data_hot, remote_cluster_client, master, data_cold, data, data_warm]
  1> [2020-11-16T08:00:05,588][INFO ][o.e.d.DiscoveryModule    ] [testTimeFields] using discovery type [zen] and seed hosts providers [settings, file]
  1> [2020-11-16T08:00:05,845][INFO ][o.e.n.Node               ] [testTimeFields] initialized
  1> [2020-11-16T08:00:05,854][INFO ][o.e.n.Node               ] [testTimeFields] version[8.0.0-SNAPSHOT], pid[5741], build[unknown/unknown/0a2891e1e2662d34235b92d3e86977c2d42146c2/2020-11-16T13:58:40.647513Z], OS[Linux/4.15.0-1086-gcp/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/11.0.2/11.0.2+7]
  1> [2020-11-16T08:00:05,855][INFO ][o.e.n.Node               ] [testTimeFields] JVM home [/var/lib/jenkins/.java/openjdk-11.0.2-linux]
  1> [2020-11-16T08:00:05,856][DEPRECATION][o.e.d.n.Node             ] [testTimeFields] 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-16T08:00:05,857][INFO ][o.e.n.Node               ] [testTimeFields] 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=D45BD2113B5CEAE2, -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-16T08:00:05,857][WARN ][o.e.n.Node               ] [testTimeFields] version [8.0.0-SNAPSHOT] is a pre-release version of Elasticsearch and is not suitable for production
  1> [2020-11-16T08:00:05,857][INFO ][o.e.x.w.t.TimeWarpedWatcher] [testTimeFields] using time warped watchers plugin
  1> [2020-11-16T08:00:05,858][INFO ][o.e.p.PluginsService     ] [testTimeFields] no modules loaded
  1> [2020-11-16T08:00:05,859][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.analysis.common.CommonAnalysisPlugin]
  1> [2020-11-16T08:00:05,860][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.script.MockMustacheScriptEngine$TestPlugin]
  1> [2020-11-16T08:00:05,860][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.script.MockScriptService$TestPlugin]
  1> [2020-11-16T08:00:05,861][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.ESIntegTestCase$AssertActionNamePlugin]
  1> [2020-11-16T08:00:05,861][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
  1> [2020-11-16T08:00:05,861][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.MockHttpTransport$TestPlugin]
  1> [2020-11-16T08:00:05,862][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.TestGeoShapeFieldMapperPlugin]
  1> [2020-11-16T08:00:05,862][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.store.MockFSIndexStore$TestPlugin]
  1> [2020-11-16T08:00:05,865][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
  1> [2020-11-16T08:00:05,865][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.xpack.datastreams.DataStreamsPlugin]
  1> [2020-11-16T08:00:05,866][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.xpack.ilm.IndexLifecycle]
  1> [2020-11-16T08:00:05,866][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.xpack.watcher.test.TimeWarpedWatcher]
  1> [2020-11-16T08:00:05,887][INFO ][o.e.e.NodeEnvironment    ] [testTimeFields] using [1] data paths, mounts [[/dev/shm (tmpfs)]], net usable_space [44.1gb], net total_space [47.2gb], types [tmpfs]
  1> [2020-11-16T08:00:05,888][INFO ][o.e.e.NodeEnvironment    ] [testTimeFields] heap size [512mb], compressed ordinary object pointers [true]
  1> [2020-11-16T08:00:05,890][INFO ][o.e.n.Node               ] [testTimeFields] node name [node_s1], node ID [_1Jb8Gf4TlyrWFdph-1I0A], cluster name [SUITE-TEST_WORKER_VM=[12]-CLUSTER_SEED=[4533184138362207540]-HASH=[26977DF3EC]-cluster], roles [ingest, data_content, data_hot, remote_cluster_client, master, data_cold, data, data_warm]
  1> [2020-11-16T08:00:06,036][INFO ][o.e.d.DiscoveryModule    ] [testTimeFields] using discovery type [zen] and seed hosts providers [settings, file]
  1> [2020-11-16T08:00:06,169][INFO ][o.e.n.Node               ] [testTimeFields] initialized
  1> [2020-11-16T08:00:06,172][INFO ][o.e.n.Node               ] [testTimeFields] version[8.0.0-SNAPSHOT], pid[5741], build[unknown/unknown/0a2891e1e2662d34235b92d3e86977c2d42146c2/2020-11-16T13:58:40.647513Z], OS[Linux/4.15.0-1086-gcp/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/11.0.2/11.0.2+7]
  1> [2020-11-16T08:00:06,172][INFO ][o.e.n.Node               ] [testTimeFields] JVM home [/var/lib/jenkins/.java/openjdk-11.0.2-linux]
  1> [2020-11-16T08:00:06,173][DEPRECATION][o.e.d.n.Node             ] [testTimeFields] 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-16T08:00:06,173][INFO ][o.e.n.Node               ] [testTimeFields] 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=D45BD2113B5CEAE2, -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-16T08:00:06,174][WARN ][o.e.n.Node               ] [testTimeFields] version [8.0.0-SNAPSHOT] is a pre-release version of Elasticsearch and is not suitable for production
  1> [2020-11-16T08:00:06,174][INFO ][o.e.x.w.t.TimeWarpedWatcher] [testTimeFields] using time warped watchers plugin
  1> [2020-11-16T08:00:06,175][INFO ][o.e.p.PluginsService     ] [testTimeFields] no modules loaded
  1> [2020-11-16T08:00:06,175][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.analysis.common.CommonAnalysisPlugin]
  1> [2020-11-16T08:00:06,175][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.script.MockMustacheScriptEngine$TestPlugin]
  1> [2020-11-16T08:00:06,175][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.script.MockScriptService$TestPlugin]
  1> [2020-11-16T08:00:06,175][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.ESIntegTestCase$AssertActionNamePlugin]
  1> [2020-11-16T08:00:06,175][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
  1> [2020-11-16T08:00:06,176][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.MockHttpTransport$TestPlugin]
  1> [2020-11-16T08:00:06,176][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.TestGeoShapeFieldMapperPlugin]
  1> [2020-11-16T08:00:06,176][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.test.store.MockFSIndexStore$TestPlugin]
  1> [2020-11-16T08:00:06,176][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.transport.nio.MockNioTransportPlugin]
  1> [2020-11-16T08:00:06,176][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.xpack.datastreams.DataStreamsPlugin]
  1> [2020-11-16T08:00:06,176][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.xpack.ilm.IndexLifecycle]
  1> [2020-11-16T08:00:06,176][INFO ][o.e.p.PluginsService     ] [testTimeFields] loaded plugin [org.elasticsearch.xpack.watcher.test.TimeWarpedWatcher]
  1> [2020-11-16T08:00:06,180][INFO ][o.e.e.NodeEnvironment    ] [testTimeFields] using [1] data paths, mounts [[/dev/shm (tmpfs)]], net usable_space [44.1gb], net total_space [47.2gb], types [tmpfs]
  1> [2020-11-16T08:00:06,180][INFO ][o.e.e.NodeEnvironment    ] [testTimeFields] heap size [512mb], compressed ordinary object pointers [true]
  1> [2020-11-16T08:00:06,183][INFO ][o.e.n.Node               ] [testTimeFields] node name [node_s2], node ID [f4YQVbTVS4SnA9BIMVkP7w], cluster name [SUITE-TEST_WORKER_VM=[12]-CLUSTER_SEED=[4533184138362207540]-HASH=[26977DF3EC]-cluster], roles [ingest, data_content, data_hot, remote_cluster_client, master, data_cold, data, data_warm]
  1> [2020-11-16T08:00:06,355][INFO ][o.e.d.DiscoveryModule    ] [testTimeFields] using discovery type [zen] and seed hosts providers [settings, file]
  1> [2020-11-16T08:00:06,449][INFO ][o.e.n.Node               ] [testTimeFields] initialized
  1> [2020-11-16T08:00:06,475][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[12]-CLUSTER_SEED=[4533184138362207540]-HASH=[26977DF3EC]-cluster[T#1]]] starting ...
  1> [2020-11-16T08:00:06,499][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[12]-CLUSTER_SEED=[4533184138362207540]-HASH=[26977DF3EC]-cluster[T#2]]] starting ...
  1> [2020-11-16T08:00:06,500][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[12]-CLUSTER_SEED=[4533184138362207540]-HASH=[26977DF3EC]-cluster[T#3]]] starting ...
  1> [2020-11-16T08:00:06,678][INFO ][o.e.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[12]-CLUSTER_SEED=[4533184138362207540]-HASH=[26977DF3EC]-cluster[T#3]]] publish_address {127.0.0.1:43081}, bound_addresses {[::1]:37795}, {127.0.0.1:43081}
  1> [2020-11-16T08:00:06,680][INFO ][o.e.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[12]-CLUSTER_SEED=[4533184138362207540]-HASH=[26977DF3EC]-cluster[T#1]]] publish_address {127.0.0.1:41125}, bound_addresses {[::1]:46449}, {127.0.0.1:41125}
  1> [2020-11-16T08:00:06,690][INFO ][o.e.t.TransportService   ] [[test_SUITE-TEST_WORKER_VM=[12]-CLUSTER_SEED=[4533184138362207540]-HASH=[26977DF3EC]-cluster[T#2]]] publish_address {127.0.0.1:35451}, bound_addresses {[::1]:42731}, {127.0.0.1:35451}
  1> [2020-11-16T08:00:07,071][INFO ][o.e.c.c.Coordinator      ] [node_s2] setting initial configuration to VotingConfiguration{f4YQVbTVS4SnA9BIMVkP7w,{bootstrap-placeholder}-node_s1,YO4C_IYjQK-ZGcRknbg2oQ}
  1> [2020-11-16T08:00:07,313][INFO ][o.e.c.s.MasterService    ] [node_s2] elected-as-master ([2] nodes joined)[{node_s2}{f4YQVbTVS4SnA9BIMVkP7w}{g4ZszcN5SWO9gApKFBZxIg}{127.0.0.1}{127.0.0.1:43081}{cdhimrsw}{xpack.installed=true} elect leader, {node_s0}{YO4C_IYjQK-ZGcRknbg2oQ}{G0mNLSZxSfWhYg6BUrwFNw}{127.0.0.1}{127.0.0.1:41125}{cdhimrsw}{xpack.installed=true} elect leader, _BECOME_MASTER_TASK_, _FINISH_ELECTION_], node-join[{node_s1}{_1Jb8Gf4TlyrWFdph-1I0A}{LSlwAhOKSB6FaaqKFxfINg}{127.0.0.1}{127.0.0.1:35451}{cdhimrsw}{xpack.installed=true} join existing leader], term: 1, version: 1, delta: master node changed {previous [], current [{node_s2}{f4YQVbTVS4SnA9BIMVkP7w}{g4ZszcN5SWO9gApKFBZxIg}{127.0.0.1}{127.0.0.1:43081}{cdhimrsw}{xpack.installed=true}]}, added {{node_s0}{YO4C_IYjQK-ZGcRknbg2oQ}{G0mNLSZxSfWhYg6BUrwFNw}{127.0.0.1}{127.0.0.1:41125}{cdhimrsw}{xpack.installed=true},{node_s1}{_1Jb8Gf4TlyrWFdph-1I0A}{LSlwAhOKSB6FaaqKFxfINg}{127.0.0.1}{127.0.0.1:35451}{cdhimrsw}{xpack.installed=true}}
  1> [2020-11-16T08:00:07,362][INFO ][o.e.c.c.CoordinationState] [node_s2] cluster UUID set to [xpZajv7mRTSRLOkxkgJvJg]
  1> [2020-11-16T08:00:07,362][INFO ][o.e.c.c.CoordinationState] [node_s0] cluster UUID set to [xpZajv7mRTSRLOkxkgJvJg]
  1> [2020-11-16T08:00:07,402][INFO ][o.e.c.c.CoordinationState] [node_s1] cluster UUID set to [xpZajv7mRTSRLOkxkgJvJg]
  1> [2020-11-16T08:00:07,405][INFO ][o.e.c.s.ClusterApplierService] [node_s0] master node changed {previous [], current [{node_s2}{f4YQVbTVS4SnA9BIMVkP7w}{g4ZszcN5SWO9gApKFBZxIg}{127.0.0.1}{127.0.0.1:43081}{cdhimrsw}{xpack.installed=true}]}, added {{node_s2}{f4YQVbTVS4SnA9BIMVkP7w}{g4ZszcN5SWO9gApKFBZxIg}{127.0.0.1}{127.0.0.1:43081}{cdhimrsw}{xpack.installed=true},{node_s1}{_1Jb8Gf4TlyrWFdph-1I0A}{LSlwAhOKSB6FaaqKFxfINg}{127.0.0.1}{127.0.0.1:35451}{cdhimrsw}{xpack.installed=true}}, term: 1, version: 1, reason: ApplyCommitRequest{term=1, version=1, sourceNode={node_s2}{f4YQVbTVS4SnA9BIMVkP7w}{g4ZszcN5SWO9gApKFBZxIg}{127.0.0.1}{127.0.0.1:43081}{cdhimrsw}{xpack.installed=true}}
  1> [2020-11-16T08:00:07,406][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[12]-CLUSTER_SEED=[4533184138362207540]-HASH=[26977DF3EC]-cluster[T#1]]] started
  1> [2020-11-16T08:00:07,420][INFO ][o.e.c.s.ClusterApplierService] [node_s1] master node changed {previous [], current [{node_s2}{f4YQVbTVS4SnA9BIMVkP7w}{g4ZszcN5SWO9gApKFBZxIg}{127.0.0.1}{127.0.0.1:43081}{cdhimrsw}{xpack.installed=true}]}, added {{node_s0}{YO4C_IYjQK-ZGcRknbg2oQ}{G0mNLSZxSfWhYg6BUrwFNw}{127.0.0.1}{127.0.0.1:41125}{cdhimrsw}{xpack.installed=true},{node_s2}{f4YQVbTVS4SnA9BIMVkP7w}{g4ZszcN5SWO9gApKFBZxIg}{127.0.0.1}{127.0.0.1:43081}{cdhimrsw}{xpack.installed=true}}, term: 1, version: 1, reason: ApplyCommitRequest{term=1, version=1, sourceNode={node_s2}{f4YQVbTVS4SnA9BIMVkP7w}{g4ZszcN5SWO9gApKFBZxIg}{127.0.0.1}{127.0.0.1:43081}{cdhimrsw}{xpack.installed=true}}
  1> [2020-11-16T08:00:07,421][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[12]-CLUSTER_SEED=[4533184138362207540]-HASH=[26977DF3EC]-cluster[T#2]]] started
  1> [2020-11-16T08:00:07,431][INFO ][o.e.c.s.ClusterApplierService] [node_s2] master node changed {previous [], current [{node_s2}{f4YQVbTVS4SnA9BIMVkP7w}{g4ZszcN5SWO9gApKFBZxIg}{127.0.0.1}{127.0.0.1:43081}{cdhimrsw}{xpack.installed=true}]}, added {{node_s0}{YO4C_IYjQK-ZGcRknbg2oQ}{G0mNLSZxSfWhYg6BUrwFNw}{127.0.0.1}{127.0.0.1:41125}{cdhimrsw}{xpack.installed=true},{node_s1}{_1Jb8Gf4TlyrWFdph-1I0A}{LSlwAhOKSB6FaaqKFxfINg}{127.0.0.1}{127.0.0.1:35451}{cdhimrsw}{xpack.installed=true}}, term: 1, version: 1, reason: Publication{term=1, version=1}
  1> [2020-11-16T08:00:07,603][INFO ][o.e.n.Node               ] [[test_SUITE-TEST_WORKER_VM=[12]-CLUSTER_SEED=[4533184138362207540]-HASH=[26977DF3EC]-cluster[T#3]]] started
  1> [2020-11-16T08:00:07,742][INFO ][o.e.g.GatewayService     ] [node_s2] recovered [0] indices into cluster_state
  1> [2020-11-16T08:00:07,801][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s2] adding index template [.slm-history] for index patterns [.slm-history-5*]
  1> [2020-11-16T08:00:07,920][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s2] adding index template [.watch-history-14] for index patterns [.watcher-history-14*]
  1> [2020-11-16T08:00:07,999][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s2] adding index template [.watches] for index patterns [.watches*]
  1> [2020-11-16T08:00:08,091][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s2] adding index template [.triggered_watches] for index patterns [.triggered_watches*]
  1> [2020-11-16T08:00:08,155][INFO ][o.e.x.i.a.TransportPutLifecycleAction] [node_s2] adding index lifecycle policy [slm-history-ilm-policy]
  1> [2020-11-16T08:00:08,316][INFO ][o.e.x.i.a.TransportPutLifecycleAction] [node_s2] adding index lifecycle policy [watch-history-ilm-policy]
  1> [2020-11-16T08:00:08,717][INFO ][o.e.l.LicenseService     ] [node_s0] license [aebb3925-7cb2-44c6-8d25-d1c57dc63882] mode [trial] - valid
  1> [2020-11-16T08:00:08,768][INFO ][o.e.l.LicenseService     ] [node_s1] license [aebb3925-7cb2-44c6-8d25-d1c57dc63882] mode [trial] - valid
  1> [2020-11-16T08:00:08,922][INFO ][o.e.l.LicenseService     ] [node_s2] license [aebb3925-7cb2-44c6-8d25-d1c57dc63882] mode [trial] - valid
  1> [2020-11-16T08:00:08,971][WARN ][o.e.c.m.MetadataIndexTemplateService] [node_s2] 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
  1> [2020-11-16T08:00:08,972][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s2] adding template [random_index_template] for index patterns [*]
  1> [2020-11-16T08:00:09,021][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] [HistoryTemplateTimeMappingsTests#testTimeFields]: all set up test
  1> [2020-11-16T08:00:09,025][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] [HistoryTemplateTimeMappingsTests#testTimeFields]: freezing time on nodes
  1> [2020-11-16T08:00:09,036][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] 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]]
  1> [2020-11-16T08:00:09,066][INFO ][o.e.x.w.WatcherService   ] [node_s0] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-16T08:00:09,067][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s0] watcher has stopped
  1> [2020-11-16T08:00:09,101][INFO ][o.e.x.w.WatcherService   ] [node_s1] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-16T08:00:09,102][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s1] watcher has stopped
  1> [2020-11-16T08:00:09,112][INFO ][o.e.x.w.WatcherService   ] [node_s2] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-16T08:00:09,112][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s2] watcher has stopped
  1> [2020-11-16T08:00:09,118][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] 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]]
  1> [2020-11-16T08:00:09,122][DEPRECATION][o.e.d.c.m.MetadataCreateIndexService] [node_s2] 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-16T08:00:09,142][INFO ][o.e.c.m.MetadataCreateIndexService] [node_s2] [.watches] creating index, cause [api], templates [.watches], shards [2]/[0]
  1> [2020-11-16T08:00:09,144][INFO ][o.e.c.r.a.AllocationService] [node_s2] updating number_of_replicas to [1] for indices [.watches]
  1> [2020-11-16T08:00:09,784][DEPRECATION][o.e.d.c.m.MetadataCreateIndexService] [node_s2] 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-16T08:00:09,796][INFO ][o.e.c.m.MetadataCreateIndexService] [node_s2] [.triggered_watches] creating index, cause [api], templates [.triggered_watches], shards [1]/[1]
  1> [2020-11-16T08:00:10,189][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STOPPED], Tuple [v1=node_s2, v2=STOPPED], Tuple [v1=node_s1, v2=STOPPED]]
  1> [2020-11-16T08:00:10,516][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTING], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTING]]
  1> [2020-11-16T08:00:10,598][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTING], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTING]]
  1> [2020-11-16T08:00:10,635][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTING], Tuple [v1=node_s2, v2=STARTING], Tuple [v1=node_s1, v2=STARTING]]
  1> [2020-11-16T08:00:10,656][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] waiting to start watcher, current states [Tuple [v1=node_s0, v2=STARTED], Tuple [v1=node_s2, v2=STARTED], Tuple [v1=node_s1, v2=STARTED]]
  1> [2020-11-16T08:00:10,800][INFO ][o.e.x.w.WatcherService   ] [node_s1] reloading watcher, reason [new local watcher shard allocation ids], cancelled [0] queued tasks
  1> [2020-11-16T08:00:10,846][INFO ][o.e.x.w.WatcherService   ] [node_s2] reloading watcher, reason [new local watcher shard allocation ids], cancelled [0] queued tasks
  1> [2020-11-16T08:00:10,861][INFO ][o.e.c.r.a.AllocationService] [node_s2] 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-16T08:00:10,969][INFO ][o.e.x.w.t.ScheduleTriggerEngineMock] [testTimeFields] not executing watch [_id] on this scheduler because it is paused
  1> [2020-11-16T08:00:10,969][INFO ][o.e.x.w.t.ScheduleTriggerEngineMock] [testTimeFields] not executing watch [_id] on this scheduler because it is paused
  1> [2020-11-16T08:00:11,013][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] [#testTimeFields]: clearing watcher state
  1> [2020-11-16T08:00:11,016][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] 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]]
  1> [2020-11-16T08:00:11,072][INFO ][o.e.x.w.WatcherService   ] [node_s1] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-16T08:00:11,072][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s1] watcher has stopped
  1> [2020-11-16T08:00:11,074][INFO ][o.e.x.w.WatcherService   ] [node_s0] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-16T08:00:11,075][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s0] watcher has stopped
  1> [2020-11-16T08:00:11,082][INFO ][o.e.x.w.WatcherService   ] [node_s2] stopping watch service, reason [watcher manually marked to shutdown by cluster state update]
  1> [2020-11-16T08:00:11,082][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s2] watcher has stopped
  1> [2020-11-16T08:00:11,088][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] 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]]
  1> [2020-11-16T08:00:11,089][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] [HistoryTemplateTimeMappingsTests#testTimeFields]: cleaning up after test
  1> [2020-11-16T08:00:11,089][INFO ][o.e.t.InternalTestCluster] [testTimeFields] Clearing active scheme time frozen, expected healing time 0s
  1> [2020-11-16T08:00:11,164][INFO ][o.e.c.m.MetadataDeleteIndexService] [node_s2] [.watches/KHeE-UCBTj6TbAQukm6nKQ] deleting index
  1> [2020-11-16T08:00:11,164][INFO ][o.e.c.m.MetadataDeleteIndexService] [node_s2] [.triggered_watches/e0wklGcTR0OUp6AC4V1s9Q] deleting index
  1> [2020-11-16T08:00:11,290][INFO ][o.e.c.m.MetadataIndexTemplateService] [node_s2] removing template [random_index_template]
  1> [2020-11-16T08:00:11,340][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] [HistoryTemplateTimeMappingsTests#testTimeFields]: cleaned up after test
  1> [2020-11-16T08:00:11,340][INFO ][o.e.x.w.h.HistoryTemplateTimeMappingsTests] [testTimeFields] after test
  2> REPRODUCE WITH: ./gradlew ':x-pack:plugin:watcher:internalClusterTest' --tests "org.elasticsearch.xpack.watcher.history.HistoryTemplateTimeMappingsTests.testTimeFields" -Dtests.seed=D45BD2113B5CEAE2 -Dtests.security.manager=true -Dtests.locale=tr -Dtests.timezone=America/North_Dakota/New_Salem -Druntime.java=11
elasticmachine commented 3 years ago

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

probakowski commented 3 years ago

Should be fixed by #65186