Skip to content

Commit 11abc8d

Browse files
authored
[8.x] Limit the log line length for s3 deletion error (#123953) (#124169)
* Limit the log line length for s3 deletion error (#123953) If all items fail to delete, the current warning log builds a huge string to include all of them (up to 1000). This PR limits the string length to first 10 entries. Relates: #123630 (cherry picked from commit a9432ba) # Conflicts: # modules/repository-s3/src/main/java/org/elasticsearch/repositories/s3/S3BlobStore.java # modules/repository-s3/src/test/java/org/elasticsearch/repositories/s3/S3BlobContainerRetriesTests.java * fix backport
1 parent 0f58537 commit 11abc8d

File tree

2 files changed

+80
-8
lines changed

2 files changed

+80
-8
lines changed

modules/repository-s3/src/main/java/org/elasticsearch/repositories/s3/S3BlobStore.java

Lines changed: 21 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -51,7 +51,6 @@
5151
import java.util.concurrent.atomic.LongAdder;
5252
import java.util.stream.Collectors;
5353

54-
import static org.elasticsearch.core.Strings.format;
5554
import static org.elasticsearch.rest.RestStatus.REQUESTED_RANGE_NOT_SATISFIED;
5655

5756
class S3BlobStore implements BlobStore {
@@ -383,13 +382,7 @@ private void deletePartition(
383382
} catch (MultiObjectDeleteException e) {
384383
// We are sending quiet mode requests so we can't use the deleted keys entry on the exception and instead
385384
// first remove all keys that were sent in the request and then add back those that ran into an exception.
386-
logger.warn(
387-
() -> format(
388-
"Failed to delete some blobs %s",
389-
e.getErrors().stream().map(err -> "[" + err.getKey() + "][" + err.getCode() + "][" + err.getMessage() + "]").toList()
390-
),
391-
e
392-
);
385+
logger.warn(buildDeletionErrorMessage(e), e);
393386
deletionExceptions.useOrMaybeSuppress(e);
394387
} catch (AmazonClientException e) {
395388
// 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(
398391
}
399392
}
400393

394+
private String buildDeletionErrorMessage(MultiObjectDeleteException e) {
395+
final var sb = new StringBuilder("Failed to delete some blobs ");
396+
final var errors = e.getErrors();
397+
for (int i = 0; i < errors.size() && i < MAX_DELETE_EXCEPTIONS; i++) {
398+
final var err = errors.get(i);
399+
sb.append("[").append(err.getKey()).append("][").append(err.getCode()).append("][").append(err.getMessage()).append("]");
400+
if (i < errors.size() - 1) {
401+
sb.append(",");
402+
}
403+
}
404+
if (errors.size() > MAX_DELETE_EXCEPTIONS) {
405+
sb.append("... (")
406+
.append(errors.size())
407+
.append(" in total, ")
408+
.append(errors.size() - MAX_DELETE_EXCEPTIONS)
409+
.append(" omitted)");
410+
}
411+
return sb.toString();
412+
}
413+
401414
private static DeleteObjectsRequest bulkDelete(OperationPurpose purpose, S3BlobStore blobStore, List<String> blobs) {
402415
final DeleteObjectsRequest deleteObjectsRequest = new DeleteObjectsRequest(blobStore.bucket()).withKeys(
403416
blobs.toArray(Strings.EMPTY_ARRAY)

modules/repository-s3/src/test/java/org/elasticsearch/repositories/s3/S3BlobContainerRetriesTests.java

Lines changed: 59 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,7 @@
1919
import com.sun.net.httpserver.HttpHandler;
2020

2121
import org.apache.http.HttpStatus;
22+
import org.apache.logging.log4j.Level;
2223
import org.elasticsearch.ExceptionsHelper;
2324
import org.elasticsearch.cluster.metadata.RepositoryMetadata;
2425
import org.elasticsearch.common.blobstore.BlobContainer;
@@ -44,10 +45,12 @@
4445
import org.elasticsearch.repositories.RepositoriesMetrics;
4546
import org.elasticsearch.repositories.blobstore.AbstractBlobContainerRetriesTestCase;
4647
import org.elasticsearch.repositories.blobstore.BlobStoreTestUtil;
48+
import org.elasticsearch.rest.RestStatus;
4749
import org.elasticsearch.telemetry.InstrumentType;
4850
import org.elasticsearch.telemetry.Measurement;
4951
import org.elasticsearch.telemetry.RecordingMeterRegistry;
5052
import org.elasticsearch.test.ESTestCase;
53+
import org.elasticsearch.test.MockLog;
5154
import org.elasticsearch.watcher.ResourceWatcherService;
5255
import org.hamcrest.Matcher;
5356
import org.junit.After;
@@ -58,6 +61,7 @@
5861
import java.io.FilterInputStream;
5962
import java.io.IOException;
6063
import java.io.InputStream;
64+
import java.io.InputStreamReader;
6165
import java.net.InetSocketAddress;
6266
import java.net.SocketTimeoutException;
6367
import java.net.UnknownHostException;
@@ -72,6 +76,7 @@
7276
import java.util.concurrent.atomic.AtomicBoolean;
7377
import java.util.concurrent.atomic.AtomicInteger;
7478
import java.util.concurrent.atomic.AtomicLong;
79+
import java.util.regex.Pattern;
7580

7681
import static org.elasticsearch.repositories.blobstore.BlobStoreTestUtil.randomNonDataPurpose;
7782
import static org.elasticsearch.repositories.blobstore.BlobStoreTestUtil.randomPurpose;
@@ -806,6 +811,60 @@ public void testSuppressedDeletionErrorsAreCapped() {
806811
assertThat(exception.getCause().getSuppressed().length, lessThan(S3BlobStore.MAX_DELETE_EXCEPTIONS));
807812
}
808813

814+
public void testTrimmedLogAndCappedSuppressedErrorOnMultiObjectDeletionException() {
815+
final TimeValue readTimeout = TimeValue.timeValueMillis(randomIntBetween(100, 500));
816+
int maxBulkDeleteSize = randomIntBetween(10, 30);
817+
final BlobContainer blobContainer = createBlobContainer(1, readTimeout, true, null, maxBulkDeleteSize);
818+
819+
final Pattern pattern = Pattern.compile("<Key>(.+?)</Key>");
820+
httpServer.createContext("/", exchange -> {
821+
if (exchange.getRequestMethod().equals("POST") && exchange.getRequestURI().toString().startsWith("/bucket/?delete")) {
822+
final String requestBody = Streams.copyToString(new InputStreamReader(exchange.getRequestBody(), StandardCharsets.UTF_8));
823+
final var matcher = pattern.matcher(requestBody);
824+
final StringBuilder deletes = new StringBuilder();
825+
deletes.append("<?xml version=\"1.0\" encoding=\"UTF-8\"?>");
826+
deletes.append("<DeleteResult>");
827+
while (matcher.find()) {
828+
final String key = matcher.group(1);
829+
deletes.append("<Error>");
830+
deletes.append("<Code>").append(randomAlphaOfLength(10)).append("</Code>");
831+
deletes.append("<Key>").append(key).append("</Key>");
832+
deletes.append("<Message>").append(randomAlphaOfLength(40)).append("</Message>");
833+
deletes.append("</Error>");
834+
}
835+
deletes.append("</DeleteResult>");
836+
837+
byte[] response = deletes.toString().getBytes(StandardCharsets.UTF_8);
838+
exchange.getResponseHeaders().add("Content-Type", "application/xml");
839+
exchange.sendResponseHeaders(RestStatus.OK.getStatus(), response.length);
840+
exchange.getResponseBody().write(response);
841+
exchange.close();
842+
} else {
843+
fail("expected only deletions");
844+
}
845+
});
846+
var blobs = randomList(maxBulkDeleteSize, maxBulkDeleteSize, ESTestCase::randomIdentifier);
847+
try (var mockLog = MockLog.capture(S3BlobStore.class)) {
848+
mockLog.addExpectation(
849+
new MockLog.SeenEventExpectation(
850+
"deletion log",
851+
S3BlobStore.class.getCanonicalName(),
852+
Level.WARN,
853+
blobs.size() > S3BlobStore.MAX_DELETE_EXCEPTIONS
854+
? "Failed to delete some blobs [*... (* in total, * omitted)"
855+
: "Failed to delete some blobs [*]"
856+
)
857+
);
858+
var exception = expectThrows(
859+
IOException.class,
860+
"deletion should not succeed",
861+
() -> blobContainer.deleteBlobsIgnoringIfNotExists(randomPurpose(), blobs.iterator())
862+
);
863+
assertThat(exception.getCause().getSuppressed().length, lessThan(S3BlobStore.MAX_DELETE_EXCEPTIONS));
864+
mockLog.awaitAllExpectationsMatched();
865+
}
866+
}
867+
809868
@Override
810869
protected Matcher<Integer> getMaxRetriesMatcher(int maxRetries) {
811870
// some attempts make meaningful progress and do not count towards the max retry limit

0 commit comments

Comments
 (0)