aws-sdk-java-v2: S3Exception when uploading - "The difference between the request time and the current time is too large"

Describe the bug

When trying to upload a large file from a box with restricted bandwidth (100Mb/s) using multiple parts to S3 we receive an S3Exception with reason "The difference between the request time and the current time is too large. "

We checked the clocks on the server and clock sync was fine (under 2 seconds with S3 clock from what we can tell).

We believe the issue is that the upload is being split into multiple parts and at this point the headers for the upload are being generated but the actual uploading of the some of the parts is being delayed by up to 15 minutes (believe the timeout is 15 minutes https://web.archive.org/web/20170606231417/http://www.bucketexplorer.com/documentation/amazon-s3--difference-between-requesttime-currenttime-too-large.html) due to the restricted bandwidth, resulting in the upload to fail.

Expected Behavior

We would expect the upload to succeed rather than fail due to “The difference between the request time and the current time is too large”

Current Behavior

The below exception is thrown and the upload fails

Exception in thread "main" java.util.concurrent.CompletionException: software.amazon.awssdk.services.s3.model.S3Exception: The difference between the request time and the current time is too large. (Service: S3, Status Code: 403, Request ID: MN0F38BHPDRXNVPM, Extended Request ID: az4zMjKJfCKwkft8X4CFFuyp100bPk4ouYV8XsGGu1X5ROGc0iCrg8mkqJdj2fG0G3uUq3OPmP4=)
        at software.amazon.awssdk.utils.CompletableFutureUtils.errorAsCompletionException(CompletableFutureUtils.java:65)
        at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncExecutionFailureExceptionReportingStage.lambda$execute$0(AsyncExecutionFailureExceptionReportingStage.java:51)
        at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
        at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
        at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2162)
        at software.amazon.awssdk.utils.CompletableFutureUtils.lambda$forwardExceptionTo$0(CompletableFutureUtils.java:79)
        at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863)
        at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
        at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2162)
        at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncRetryableStage$RetryingExecutor.maybeAttemptExecute(AsyncRetryableStage.java:103)
        at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncRetryableStage$RetryingExecutor.maybeRetryExecute(AsyncRetryableStage.java:184)
        at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncRetryableStage$RetryingExecutor.lambda$attemptExecute$1(AsyncRetryableStage.java:170)
        at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863)
        at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
        at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147)
        at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeAsyncHttpRequestStage.lambda$null$0(MakeAsyncHttpRequestStage.java:105)
        at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863)
        at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
        at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147)
        at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeAsyncHttpRequestStage.lambda$executeHttpRequest$3(MakeAsyncHttpRequestStage.java:163)
        at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863)
        at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841)
        at java.base/java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:482)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: software.amazon.awssdk.services.s3.model.S3Exception: The difference between the request time and the current time is too large. (Service: S3, Status Code: 403, Request ID: MN0F38BHPDRXNVPM, Extended Request ID: az4zMjKJfCKwkft8X4CFFuyp100bPk4ouYV8XsGGu1X5ROGc0iCrg8mkqJdj2fG0G3uUq3OPmP4=)
        at software.amazon.awssdk.protocols.xml.internal.unmarshall.AwsXmlPredicatedResponseHandler.handleErrorResponse(AwsXmlPredicatedResponseHandler.java:156)
        at software.amazon.awssdk.protocols.xml.internal.unmarshall.AwsXmlPredicatedResponseHandler.handleResponse(AwsXmlPredicatedResponseHandler.java:108)
        at software.amazon.awssdk.protocols.xml.internal.unmarshall.AwsXmlPredicatedResponseHandler.handle(AwsXmlPredicatedResponseHandler.java:85)
        at software.amazon.awssdk.protocols.xml.internal.unmarshall.AwsXmlPredicatedResponseHandler.handle(AwsXmlPredicatedResponseHandler.java:43)
        at software.amazon.awssdk.core.internal.handler.BaseClientHandler.lambda$successTransformationResponseHandler$7(BaseClientHandler.java:270)
        at software.amazon.awssdk.core.internal.http.async.AsyncResponseHandler.lambda$prepare$0(AsyncResponseHandler.java:89)
        at java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
        at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147)
        at software.amazon.awssdk.core.internal.http.async.AsyncResponseHandler$BaosSubscriber.onComplete(AsyncResponseHandler.java:132)
        at software.amazon.awssdk.utils.async.SimplePublisher.doProcessQueue(SimplePublisher.java:275)
        at software.amazon.awssdk.utils.async.SimplePublisher.processEventQueue(SimplePublisher.java:224)
        at software.amazon.awssdk.utils.async.SimplePublisher.complete(SimplePublisher.java:157)
        at java.base/java.util.concurrent.CompletableFuture.uniRunNow(CompletableFuture.java:819)
        at java.base/java.util.concurrent.CompletableFuture.uniRunStage(CompletableFuture.java:803)
        at java.base/java.util.concurrent.CompletableFuture.thenRun(CompletableFuture.java:2195)
        at software.amazon.awssdk.services.s3.internal.crt.S3CrtResponseHandlerAdapter.onErrorResponseComplete(S3CrtResponseHandlerAdapter.java:135)
        at software.amazon.awssdk.services.s3.internal.crt.S3CrtResponseHandlerAdapter.handleError(S3CrtResponseHandlerAdapter.java:124)
        at software.amazon.awssdk.services.s3.internal.crt.S3CrtResponseHandlerAdapter.onFinished(S3CrtResponseHandlerAdapter.java:93)
        at software.amazon.awssdk.crt.s3.S3MetaRequestResponseHandlerNativeAdapter.onFinished(S3MetaRequestResponseHandlerNativeAdapter.java:24)

Reproduction Steps

This is the code we use to upload the file. Note that we run this code on 2 boxes in parallel

final S3CrtAsyncClientBuilder builder = S3AsyncClient.crtBuilder()
                .region(Region.EU_WEST_1)
                .httpConfiguration(
                        S3CrtHttpConfiguration
                                .builder()
                                .connectionTimeout(Duration.ofHours(4))
                                .build()
                )
                .credentialsProvider(awsCredentialsProvider)
                .minimumPartSizeInBytes(200L * 1024 * 1024);

        final S3AsyncClient s3Client = builder
                .build();
                
LOGGER.info("Uploading Bucket {} ObjectKey: {}", bucketName, objectKey);
        try (final S3TransferManager tm = S3TransferManager.builder().s3Client(s3Client).build())
        {
            LOGGER.info("Uploading a new object to S3 from a file\n");
            final FileUpload upload = tm.uploadFile(UploadFileRequest.builder()
                                                            .putObjectRequest(PutObjectRequest.builder().bucket(bucketName).key(objectKey).build())
                                                            .source(src)
                                                            .build());
            try
            {
                upload.completionFuture().join();
            }
            catch (final AwsServiceException ase)
            {
                LOGGER.info("Caught an AmazonServiceException, which means your request made it to Amazon S3, but was rejected with an error response for some reason.");
                LOGGER.info("Error Message:    " + ase.getMessage());
                LOGGER.info("HTTP Status Code: " + ase.statusCode());
                LOGGER.info("AWS Error Code:   " + ase.awsErrorDetails().errorCode());
                LOGGER.info("Error Type:       " + ase.awsErrorDetails().errorMessage());
                throw new IllegalStateException(ase);
            }
            catch (final SdkClientException ace)
            {
                LOGGER.info("Caught an AmazonClientException, which means the client encountered an internal error while trying to communicate with S3, such as not being able to access the network.");
                LOGGER.info("Error Message: " + ace.getMessage());
                throw new IllegalStateException(ace);
            }
        }

Possible Solution

Don’t create the headers for each part of an upload until it’s actually being uploaded.

Additional Information/Context

No response

AWS Java SDK version used

2.20.67

JDK version used

openjdk 17.0.6 2023-01-17 LTS OpenJDK Runtime Environment Corretto-17.0.6.10.1 (build 17.0.6+10-LTS) OpenJDK 64-Bit Server VM Corretto-17.0.6.10.1 (build 17.0.6+10-LTS, mixed mode, sharing)

Operating System and version

AlmaLinux 8.8 (Sapphire Caracal) Kernel: Linux 4.18.0-425.19.2.el8_7.x86_64

About this issue

  • Original URL
  • State: open
  • Created a year ago
  • Comments: 15 (5 by maintainers)

Most upvoted comments

@tom-smalls thank you for the logs, and sorry for the silence.

Yes, I can see there’s a delay between the request for partNumber=31 being prepared:

[DEBUG] [2023-07-25T16:12:57Z] [00007fd903fff700] [S3MetaRequest] - 
        id=0x7fdb44a391a0: Prepared request 0x7fd9f4004480 for part 31
[TRACE] [2023-07-25T16:12:57Z] [00007fd903fff700] [S3MetaRequest] - 
        id=0x7fdb44a391a0 Created signable 0x7fd8fc02da90 for request 0x7fd9f4004480 with message 0x7fd8fc02dae0
[INFO] [2023-07-25T16:12:57Z] [00007fd903fff700] [AuthSigning] - 
        (id=0x7fd8fc02da90) Signing successfully built canonical request for algorithm SigV4, with contents (...)

and effectively being sent:

[TRACE] [2023-07-25T16:27:58Z] [00007fda437fe700] [S3MetaRequest] - 
        id=0x7fdb44a391a0: Sending request 0x7fd9f4004480
[TRACE] [2023-07-25T16:27:58Z] [00007fda437fe700] [S3MetaRequest] - 
        id=0x7fdb44a391a0 Incoming body for request 0x7fd9f4004480. Response status: 403. Data Size: 475. connection: 0x7fd9f4002820.
[TRACE] [2023-07-25T16:27:58Z] [00007fda437fe700] [S3MetaRequest] - response body: 
<Error>
    <Code>RequestTimeTooSkewed</Code>
    <Message>The difference between the request time and the current time is too large.</Message>
    <RequestTime>20230725T161257Z</RequestTime>
    <ServerTime>2023-07-25T16:27:59Z</ServerTime>
    <MaxAllowedSkewMilliseconds>900000</MaxAllowedSkewMilliseconds>
</Error>

I’ll raise this to the CRT team. Preparing the request immediately before sending would avoid this kind of error.