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 f09097d2822e1..74cd995c7207a 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 @@ -51,7 +51,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 { @@ -383,13 +382,7 @@ private void deletePartition( } 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); } catch (AmazonClientException e) { // The AWS client threw any unexpected exception and did not execute the request at all so we do not @@ -398,6 +391,26 @@ private void deletePartition( } } + 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(); + } + private static DeleteObjectsRequest bulkDelete(OperationPurpose purpose, S3BlobStore blobStore, List blobs) { final DeleteObjectsRequest deleteObjectsRequest = new DeleteObjectsRequest(blobStore.bucket()).withKeys( blobs.toArray(Strings.EMPTY_ARRAY) 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 5dd204cdcffc9..4d727864978ef 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 @@ -19,6 +19,7 @@ import com.sun.net.httpserver.HttpHandler; import org.apache.http.HttpStatus; +import org.apache.logging.log4j.Level; import org.elasticsearch.ExceptionsHelper; import org.elasticsearch.cluster.metadata.RepositoryMetadata; import org.elasticsearch.common.blobstore.BlobContainer; @@ -44,10 +45,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; @@ -58,6 +61,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; @@ -72,6 +76,7 @@ import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.atomic.AtomicLong; +import java.util.regex.Pattern; import static org.elasticsearch.repositories.blobstore.BlobStoreTestUtil.randomNonDataPurpose; import static org.elasticsearch.repositories.blobstore.BlobStoreTestUtil.randomPurpose; @@ -806,6 +811,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