Skip to content

[8.x] Limit the log line length for s3 deletion error (#123953) #124169

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 2 commits into from
Mar 6, 2025
Merged

[8.x] Limit the log line length for s3 deletion error (#123953) #124169

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
ab92737
Limit the log line length for s3 deletion error (#123953)
ywangd Mar 6, 2025
254f7ef
fix backport
ywangd Mar 6, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
29 changes: 21 additions & 8 deletions modules/repository-s3/src/main/java/org/elasticsearch/repositories/s3/S3BlobStore.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand Down Expand Up @@ -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
Expand All @@ -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<String> blobs) {
final DeleteObjectsRequest deleteObjectsRequest = new DeleteObjectsRequest(blobStore.bucket()).withKeys(
blobs.toArray(Strings.EMPTY_ARRAY)
Expand Down
59 changes: 59 additions & 0 deletions ...itory-s3/src/test/java/org/elasticsearch/repositories/s3/S3BlobContainerRetriesTests.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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;
Expand All @@ -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;
Expand All @@ -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;
Expand Down Expand Up @@ -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("<Key>(.+?)</Key>");
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("<?xml version=\"1.0\" encoding=\"UTF-8\"?>");
deletes.append("<DeleteResult>");
while (matcher.find()) {
final String key = matcher.group(1);
deletes.append("<Error>");
deletes.append("<Code>").append(randomAlphaOfLength(10)).append("</Code>");
deletes.append("<Key>").append(key).append("</Key>");
deletes.append("<Message>").append(randomAlphaOfLength(40)).append("</Message>");
deletes.append("</Error>");
}
deletes.append("</DeleteResult>");

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<Integer> getMaxRetriesMatcher(int maxRetries) {
// some attempts make meaningful progress and do not count towards the max retry limit
Expand Down