[CI] ActivateWatchTests fails occasionally on master not able to delete index

[breskeby]

Seeing this failing occasionally (4 out of ~1200 in 7 days). I wonder if this is showing some specific issue with the test or with the infrastructure as the error seems to indicate some sort of a permission issue?

Build scan:

https://gradle-enterprise.elastic.co/s/usis5fhbuqx6y/tests/:x-pack:plugin:watcher:internalClusterTest/org.elasticsearch.xpack.watcher.transport.action.activate.ActivateWatchTests/testDeactivateAndActivate#1

Repro line:

./gradlew ':x-pack:plugin:watcher:internalClusterTest' --tests "org.elasticsearch.xpack.watcher.transport.action.activate.ActivateWatchTests.testDeactivateAndActivate" -Dtests.seed=FE8DAE73AB0A616A -Dtests.security.manager=true -Dtests.locale=ru-RU -Dtests.timezone=US/Central -Druntime.java=11

Reproduces locally?:

no.

Applicable branches:

master

Failure history:
https://gradle-enterprise.elastic.co/scans/tests?search.relativeStartTime=P7D&search.timeZoneId=Europe/Berlin&tests.container=org.elasticsearch.xpack.watcher.transport.action.activate.ActivateWatchTests&tests.sortField=FAILED&tests.test=testDeactivateAndActivate&tests.unstableOnly=true
-->
Failure excerpt:

java.lang.IllegalArgumentException: index [.ds-.watcher-history-14-2020.12.17-000001] is the write index for data stream [.watcher-history-14] and cannot be deleted

[elasticmachine]

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

[martijnvg]

During the teardown, the test attempts to delete write index of data stream. This is prohibited, a write index of a data stream must always exist (other backing indices can be deleted). The data stream should be removed in its entirety, which is what is supposed to happen via AbstractWatcherIntegrationTestCase#_cleanup(...), but somehow the test infra tries to just delete the write index. Not sure why this happens yet.

[martijnvg]

It looks like the watcher history data stream gets created after watcher has been stopped and the previous data stream has been removed:

1> [2020-12-17T03:30:00,522][INFO ][o.e.x.w.WatcherLifeCycleService] [node_s0] watcher has stopped |  
-- | --
  | 1> [2020-12-17T03:30:00,525][INFO ][o.e.x.w.t.a.a.ActivateWatchTests] [testDeactivateAndActivate] waiting to stop watcher, current states [Tuple [v1=node_s3 (0), v2=STOPPED], Tuple [v1=node_s2 (0), v2=STOPPED], Tuple [v1=node_s0 (0), v2=STOPPED], Tuple [v1=node_s1 (0), v2=STOPPED]] |  
  | 1> [2020-12-17T03:30:00,527][INFO ][o.e.x.d.a.DeleteDataStreamTransportAction] [node_s0] removing data stream [.watcher-history-14] |  
  | 1> [2020-12-17T03:30:00,527][INFO ][o.e.c.m.MetadataDeleteIndexService] [node_s0] [.ds-.watcher-history-14-2020.12.17-000001/S9MRwpX-SmWEaSLkl4DrNw] deleting index |  
  | 1> [2020-12-17T03:30:00,608][INFO ][o.e.x.w.t.a.a.ActivateWatchTests] [testDeactivateAndActivate] [ActivateWatchTests#testDeactivateAndActivate]: cleaning up after test |  
  | 1> [2020-12-17T03:30:00,622][INFO ][o.e.c.m.MetadataCreateIndexService] [node_s0] [.ds-.watcher-history-14-2020.12.17-000001] creating index, cause [initialize_data_stream], templates [.watch-history-14], shards [1]/[0] |  
  | 1> [2020-12-17T03:30:00,624][INFO ][o.e.c.m.MetadataCreateDataStreamService] [node_s0] adding data stream [.watcher-history-14] with write index [.ds-.watcher-history-14-2020.12.17-000001] and backing indices [] |  
  | 1> [2020-12-17T03:30:00,720][INFO ][o.e.x.i.IndexLifecycleTransition] [node_s0] moving index [.ds-.watcher-history-14-2020.12.17-000001] from [null] to [{"phase":"new","action":"complete","name":"complete"}] in policy [watch-history-ilm-policy] |  
  | 1> [2020-12-17T03:30:00,757][INFO ][o.e.c.r.a.AllocationService] [node_s0] current.health="GREEN" message="Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[.ds-.watcher-history-14-2020.12.17-000001][0]]])." previous.health="YELLOW" reason="shards started [[.ds-.watcher-history-14-2020.12.17-000001][0]]" |  
  | 1> [2020-12-17T03:30:00,837][INFO ][o.e.c.m.MetadataMappingService] [node_s0] [.ds-.watcher-history-14-2020.12.17-000001/1Ysc1vvwSZ2mHgNjxAGjgg] update_mapping [_doc]

I suspect this happens because write requests for watch history are still inflight after watcher has been stopped.
The exception is most likely thrown when the test cluster is wiped (which deletes all indices), which is after when AbstractWatcherIntegrationTestCase has removed the watcher history data stream and stopped watcher.

[hendrikmuhs]

I see the same stacktrace in a failure today:

https://gradle-enterprise.elastic.co/s/5hq6kmhcgi53i/console-log?anchor=7304

[henningandersen]

This happened in a PR build here:
https://gradle-enterprise.elastic.co/s/gwj4needgfl7s

pretty sure it is not related to my changes, since the only change I did was to merge in master.