Correctly log exceptions that are thrown during cache prewarming

[tlrx]

Today if an exception is thrown during the prewarming of (parts of) the files it is simply swallowed. This is confusing because the shard recovery state is left in a FINALIZE state but nothing in the logs can help troubleshooting why the recovery has been interrupted.

This pull request adds log traces to warn when an exception occurred during the prewarming of a part of a file. In the issue we
encountered it would have logged something like this:

[2021-06-22T13:42:10,510][WARN ][o.e.x.s.s.SearchableSnapshotDirectory] [pop-os] [test][0] prewarming failed for file [_a.cfe] org.elasticsearch.common.util.concurrent.UncategorizedExecutionException: Failed execution	at org.elasticsearch.common.util.concurrent.FutureUtils.rethrowExecutionException(FutureUtils.java:80) ~[elasticsearch-7.13.3-SNAPSHOT.jar:7.13.3-SNAPSHOT]	... Caused by: java.util.concurrent.ExecutionException: java.io.IOException: Failed to prefetch file part in cache	at org.elasticsearch.common.util.concurrent.BaseFuture$Sync.getValue(BaseFuture.java:262) ~[elasticsearch-7.13.3-SNAPSHOT.jar:7.13.3-SNAPSHOT]	... 21 more Caused by: java.io.IOException: Failed to prefetch file part in cache	at org.elasticsearch.xpack.searchablesnapshots.store.input.CachedBlobContainerIndexInput.prefetchPart(CachedBlobContainerIndexInput.java:216) ~[?:?]	... 3 more Caused by: java.nio.file.NoSuchFileException: /tmp/cluster/repo/indices/vLuVOFjKRAexJYJ7h4dVXw/0/__iWOCoAtpR2-WDCZ06eOUew	at sun.nio.fs.UnixException.translateToIOException(UnixException.java:92) ~[?:?]	... 

[elasticmachine]

Pinging @elastic/es-distributed (Team:Distributed)

[henningandersen]

LGTM.

[henningandersen]

I think this attempts to ensure that the recovery state moves to DONE? I guess that is more correct than FINALIZE, but I think we should add a test for it.

[tlrx]

It attempts to complete the grouped listener but has not other side effect besides logging a warning message if the shard is a relocation target:

elasticsearch/x-pack/plugin/searchable-snapshots/src/main/java/org/elasticsearch/xpack/searchablesnapshots/allocation/SearchableSnapshotIndexEventListener.java

Lines 78 to 90 in a5d2251

	if (success && shardRouting.isRelocationTarget()) {
	final Runnable preWarmCondition = indexShard.addCleanFilesDependency();
	preWarmListener.whenComplete(v -> preWarmCondition.run(), e -> {
	logger.warn(
	new ParameterizedMessage(
	"pre-warm operation failed for [{}] while it was the target of primary relocation [{}]",
	shardRouting.shardId(),
	shardRouting
	),
	e
	);
	preWarmCondition.run();
	});

I'm OK with leaving the recovery state in FINALIZE as this is what allowed to detect a non-fully prewarmed shard at the first place. I think that adding more logs would have helped to troubleshoot some issues when accessing repository files.

[tlrx]

Thanks @henningandersen - I've merged it like this, see #74419 (comment)