diff --git a/modules/repository-s3/src/main/java/org/elasticsearch/repositories/s3/S3BlobStore.java b/modules/repository-s3/src/main/java/org/elasticsearch/repositories/s3/S3BlobStore.java index 76ca8547a99ba..3b5c1e317b135 100644 --- a/modules/repository-s3/src/main/java/org/elasticsearch/repositories/s3/S3BlobStore.java +++ b/modules/repository-s3/src/main/java/org/elasticsearch/repositories/s3/S3BlobStore.java @@ -55,7 +55,6 @@ import java.util.concurrent.atomic.LongAdder; import java.util.stream.Collectors; -import static org.elasticsearch.core.Strings.format; import static org.elasticsearch.rest.RestStatus.REQUESTED_RANGE_NOT_SATISFIED; class S3BlobStore implements BlobStore { @@ -398,16 +397,7 @@ private void deletePartition(OperationPurpose purpose, List partition, D } catch (MultiObjectDeleteException e) { // We are sending quiet mode requests so we can't use the deleted keys entry on the exception and instead // first remove all keys that were sent in the request and then add back those that ran into an exception. - logger.warn( - () -> format( - "Failed to delete some blobs %s", - e.getErrors() - .stream() - .map(err -> "[" + err.getKey() + "][" + err.getCode() + "][" + err.getMessage() + "]") - .toList() - ), - e - ); + logger.warn(buildDeletionErrorMessage(e), e); deletionExceptions.useOrMaybeSuppress(e); return; } catch (AmazonClientException e) { @@ -430,6 +420,26 @@ private void deletePartition(OperationPurpose purpose, List partition, D } } + private String buildDeletionErrorMessage(MultiObjectDeleteException e) { + final var sb = new StringBuilder("Failed to delete some blobs "); + final var errors = e.getErrors(); + for (int i = 0; i < errors.size() && i < MAX_DELETE_EXCEPTIONS; i++) { + final var err = errors.get(i); + sb.append("[").append(err.getKey()).append("][").append(err.getCode()).append("][").append(err.getMessage()).append("]"); + if (i < errors.size() - 1) { + sb.append(","); + } + } + if (errors.size() > MAX_DELETE_EXCEPTIONS) { + sb.append("... (") + .append(errors.size()) + .append(" in total, ") + .append(errors.size() - MAX_DELETE_EXCEPTIONS) + .append(" omitted)"); + } + return sb.toString(); + } + /** * If there are remaining retries, pause for the configured interval then return true * diff --git a/modules/repository-s3/src/test/java/org/elasticsearch/repositories/s3/S3BlobContainerRetriesTests.java b/modules/repository-s3/src/test/java/org/elasticsearch/repositories/s3/S3BlobContainerRetriesTests.java index bd72cba6c2b8e..3ddb53988b3a6 100644 --- a/modules/repository-s3/src/test/java/org/elasticsearch/repositories/s3/S3BlobContainerRetriesTests.java +++ b/modules/repository-s3/src/test/java/org/elasticsearch/repositories/s3/S3BlobContainerRetriesTests.java @@ -21,6 +21,7 @@ import com.sun.net.httpserver.HttpHandler; import org.apache.http.HttpStatus; +import org.apache.logging.log4j.Level; import org.apache.lucene.index.CorruptIndexException; import org.apache.lucene.store.AlreadyClosedException; import org.elasticsearch.ExceptionsHelper; @@ -51,10 +52,12 @@ import org.elasticsearch.repositories.RepositoriesMetrics; import org.elasticsearch.repositories.blobstore.AbstractBlobContainerRetriesTestCase; import org.elasticsearch.repositories.blobstore.BlobStoreTestUtil; +import org.elasticsearch.rest.RestStatus; import org.elasticsearch.telemetry.InstrumentType; import org.elasticsearch.telemetry.Measurement; import org.elasticsearch.telemetry.RecordingMeterRegistry; import org.elasticsearch.test.ESTestCase; +import org.elasticsearch.test.MockLog; import org.elasticsearch.watcher.ResourceWatcherService; import org.hamcrest.Matcher; import org.junit.After; @@ -65,6 +68,7 @@ import java.io.FilterInputStream; import java.io.IOException; import java.io.InputStream; +import java.io.InputStreamReader; import java.net.InetSocketAddress; import java.net.SocketTimeoutException; import java.net.UnknownHostException; @@ -83,6 +87,7 @@ import java.util.concurrent.atomic.AtomicLong; import java.util.concurrent.atomic.AtomicReference; import java.util.function.IntConsumer; +import java.util.regex.Pattern; import static org.elasticsearch.repositories.blobstore.BlobStoreTestUtil.randomNonDataPurpose; import static org.elasticsearch.repositories.blobstore.BlobStoreTestUtil.randomPurpose; @@ -1106,6 +1111,60 @@ public void testSuppressedDeletionErrorsAreCapped() { assertThat(exception.getCause().getSuppressed().length, lessThan(S3BlobStore.MAX_DELETE_EXCEPTIONS)); } + public void testTrimmedLogAndCappedSuppressedErrorOnMultiObjectDeletionException() { + final TimeValue readTimeout = TimeValue.timeValueMillis(randomIntBetween(100, 500)); + int maxBulkDeleteSize = randomIntBetween(10, 30); + final BlobContainer blobContainer = createBlobContainer(1, readTimeout, true, null, maxBulkDeleteSize); + + final Pattern pattern = Pattern.compile("(.+?)"); + httpServer.createContext("/", exchange -> { + if (exchange.getRequestMethod().equals("POST") && exchange.getRequestURI().toString().startsWith("/bucket/?delete")) { + final String requestBody = Streams.copyToString(new InputStreamReader(exchange.getRequestBody(), StandardCharsets.UTF_8)); + final var matcher = pattern.matcher(requestBody); + final StringBuilder deletes = new StringBuilder(); + deletes.append(""); + deletes.append(""); + while (matcher.find()) { + final String key = matcher.group(1); + deletes.append(""); + deletes.append("").append(randomAlphaOfLength(10)).append(""); + deletes.append("").append(key).append(""); + deletes.append("").append(randomAlphaOfLength(40)).append(""); + deletes.append(""); + } + deletes.append(""); + + byte[] response = deletes.toString().getBytes(StandardCharsets.UTF_8); + exchange.getResponseHeaders().add("Content-Type", "application/xml"); + exchange.sendResponseHeaders(RestStatus.OK.getStatus(), response.length); + exchange.getResponseBody().write(response); + exchange.close(); + } else { + fail("expected only deletions"); + } + }); + var blobs = randomList(maxBulkDeleteSize, maxBulkDeleteSize, ESTestCase::randomIdentifier); + try (var mockLog = MockLog.capture(S3BlobStore.class)) { + mockLog.addExpectation( + new MockLog.SeenEventExpectation( + "deletion log", + S3BlobStore.class.getCanonicalName(), + Level.WARN, + blobs.size() > S3BlobStore.MAX_DELETE_EXCEPTIONS + ? "Failed to delete some blobs [*... (* in total, * omitted)" + : "Failed to delete some blobs [*]" + ) + ); + var exception = expectThrows( + IOException.class, + "deletion should not succeed", + () -> blobContainer.deleteBlobsIgnoringIfNotExists(randomPurpose(), blobs.iterator()) + ); + assertThat(exception.getCause().getSuppressed().length, lessThan(S3BlobStore.MAX_DELETE_EXCEPTIONS)); + mockLog.awaitAllExpectationsMatched(); + } + } + @Override protected Matcher getMaxRetriesMatcher(int maxRetries) { // some attempts make meaningful progress and do not count towards the max retry limit