[CI] IndexRecoveryIT.testRerouteRecovery : Paths exist that should have been deleted

[albertzaharovits]

Build failures: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.4+matrix-java-periodic/ES_BUILD_JAVA=java10,ES_RUNTIME_JAVA=java10,nodes=virtual&&linux/21/console

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+matrix-java-periodic/ES_BUILD_JAVA=java10,ES_RUNTIME_JAVA=java11,nodes=virtual&&linux/224/console

Root cause:

com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=5109, name=elasticsearch[node_t0][clusterApplierService#updateTask][T#1], state=RUNNABLE, group=TGRP-IndexRecoveryIT]
	at __randomizedtesting.SeedInfo.seed([E8CEC7E4E4750104:456574B0D12D6346]:0)
Caused by: java.lang.AssertionError: Paths exist that should have been deleted: [/var/lib/jenkins/workspace/elastic+elasticsearch+6.4+matrix-java-periodic/ES_BUILD_JAVA/java10/ES_RUNTIME_JAVA/java10/nodes/virtual&&linux/server/build/testrun/integTest/J1/temp/org.elasticsearch.indices.recovery.IndexRecoveryIT_E8CEC7E4E4750104-001/tempDir-004/data/nodes/0/indices/RJoRvWIVRDyM1toTfMV2tw/0]
	at __randomizedtesting.SeedInfo.seed([E8CEC7E4E4750104]:0)
	at org.elasticsearch.env.NodeEnvironment.assertPathsDoNotExist(NodeEnvironment.java:469)
	at org.elasticsearch.env.NodeEnvironment.deleteShardDirectoryUnderLock(NodeEnvironment.java:459)
	at org.elasticsearch.env.NodeEnvironment.deleteShardDirectorySafe(NodeEnvironment.java:399)
	at org.elasticsearch.indices.IndicesService.deleteShardStore(IndicesService.java:770)
	at org.elasticsearch.indices.store.IndicesStore$ShardActiveResponseHandler.lambda$allNodesResponded$2(IndicesStore.java:288)
	at org.elasticsearch.cluster.service.ClusterApplierService.lambda$runOnApplierThread$0(ClusterApplierService.java:306)
	at org.elasticsearch.cluster.service.ClusterApplierService$UpdateTask.apply(ClusterApplierService.java:155)
	at org.elasticsearch.cluster.service.ClusterApplierService.runTask(ClusterApplierService.java:399)
	at org.elasticsearch.cluster.service.ClusterApplierService$UpdateTask.run(ClusterApplierService.java:160)
	at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingRunnable.run(ThreadContext.java:624)
	at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.runAndClean(PrioritizedEsThreadPoolExecutor.java:244)
	at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.run(PrioritizedEsThreadPoolExecutor.java:207)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1135)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:844)

It does not reproduce:

REPRODUCE WITH: ./gradlew :server:integTest \
  -Dtests.seed=B4F936D0EF2B4D07 \
  -Dtests.class=org.elasticsearch.indices.recovery.IndexRecoveryIT \
  -Dtests.method="testRerouteRecovery" \
  -Dtests.security.manager=true \
  -Dtests.locale=fr-TN \
  -Dtests.timezone=Eire

[ywelsch]

Relates to #29140

[nik9000]

Another one!

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+matrix-java-periodic/ES_BUILD_JAVA=java10,ES_RUNTIME_JAVA=java11,nodes=virtual&&linux/263/console

[javanna]

Here is a different test that failed with the same error: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.4+periodic/190/console

[jpountz]

Another one: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.x+matrix-java-periodic/ES_BUILD_JAVA=java10,ES_RUNTIME_JAVA=java8,nodes=virtual&&linux/280/consoleFull. I'll disable the test.

[original-brownbear]

I figured out where this is coming from but I'm not sure how to fix it.

The issue is, that org.elasticsearch.gateway.MetaDataStateFormat#read will create a new SimpleFSDirectory for the for the _state directory without holding any lock to the shard. If this happens after the shard directory is deleted in org.elasticsearch.env.NodeEnvironment#deleteShardDirectoryUnderLock but before the assertion that the path is gone is made, then the shard path exists again containing nothing but an empty _state directory and the assertion fails.

I think ideally we should avoid creating the _state directory in org.elasticsearch.gateway.MetaDataStateFormat#read because it's a read only operation but since FSDirectory will always create its underlying path if it doesn't exist I'm not sure how to accomplish that (without adding additional locking).

[DaveCTurner]

This is a long-standing and, unfortunately, complicated issue. The fix you propose was #19338 and an alternative was #29140 (and see linked issues there for further discussion) but neither of these fixes were satisfactory.

[droberts195]

A failure occurred in https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.x+multijob-unix-compatibility/os=oraclelinux/38/console that suggests #34120 doesn't fix this in every case.

The error is this:

06:45:17 ERROR   0.76s J1 | IndicesLifecycleListenerIT.testIndexStateShardChanged <<< FAILURES!
06:45:17    > Throwable #1: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=10795, name=elasticsearch[node_t0][clusterApplierService#updateTask][T#1], state=RUNNABLE, group=TGRP-IndicesLifecycleListenerIT]
06:45:17    > 	at __randomizedtesting.SeedInfo.seed([A8D19CF9DD9EFD43:7E04533A46A0D37A]:0)
06:45:17    > Caused by: java.lang.AssertionError: Paths exist that should have been deleted: [/var/lib/jenkins/workspace/elastic+elasticsearch+6.x+multijob-unix-compatibility/os/oraclelinux/server/build/testrun/integTest/J1/temp/org.elasticsearch.indices.IndicesLifecycleListenerIT_A8D19CF9DD9EFD43-001/tempDir-002/d1/nodes/0/indices/2HM7dFt2TTqo3nNIgS8seA/2, /var/lib/jenkins/workspace/elastic+elasticsearch+6.x+multijob-unix-compatibility/os/oraclelinux/server/build/testrun/integTest/J1/temp/org.elasticsearch.indices.IndicesLifecycleListenerIT_A8D19CF9DD9EFD43-001/tempDir-002/d0/nodes/0/indices/2HM7dFt2TTqo3nNIgS8seA/2]

Looking elsewhere in the log file it seems that 2HM7dFt2TTqo3nNIgS8seA/2 is the state directory, as there are messages about .../2HM7dFt2TTqo3nNIgS8seA/2/_state/state-1.st.

The repro command for this failure was:

./gradlew :server:integTest \
  -Dtests.seed=A8D19CF9DD9EFD43 \
  -Dtests.class=org.elasticsearch.indices.IndicesLifecycleListenerIT \
  -Dtests.method="testIndexStateShardChanged" \
  -Dtests.security.manager=true \
  -Dtests.locale=es-AR \
  -Dtests.timezone=America/Toronto \
  -Dcompiler.java=10 \
  -Druntime.java=8

This didn't reproduce locally.

[DaveCTurner]

It looks like #34120 hasn't been backported to 6.x yet. @original-brownbear could you take a look?

[original-brownbear]

@DaveCTurner yea sorry about that, will do either later today or tomorrow at the very latest (sorry public holiday here today and a little busy because of it :))

[DaveCTurner]

Oh I forgot about the holiday there today. Enjoy your day off and don't worry about this, I'll try and take care of it.

[original-brownbear]

Closing this since the backporting was handling by @DaveCTurner (thanks for that! :)).