S3 TransferListener Progress percent not work properly when uploading byte arrays

[JmKanmo]

Describe the bug

0.0 => 100.0% => (4min 25sec later) => Transfer complete!

It didn't show process percent gradually.

source code

 StopWatch stopWatch = new StopWatch();

        final String WHATAP_DESTINATION_KEY = "5/myhome.com/1.0/howlong_2gb_window_1111111gngngngn_file";

        File file = new File("/Users/junmokang/whatap/files/test_files/test10.js.map");
        byte[] originBytes = IoUtils.toByteArray(new FileInputStream(file));

        S3TransferManager transferManager = S3TransferManager.builder()
                .s3Client(S3AsyncClient.crtBuilder()
                        .region(Region.US_EAST_1)
                        .targetThroughputInGbps(30.0)
                        .minimumPartSizeInBytes(30 * 1024 * 1024L)
                        .credentialsProvider(StaticCredentialsProvider.create(AwsBasicCredentials.create(WHATAP_AWS_ACCESS_KEY_ID, WHATAP_AWS_SECRET_ACCESS_KEY)))
                        .httpConfiguration(a -> {
                            NettyNioAsyncHttpClient.builder()
                                    .maxConcurrency(500)
                                    .maxPendingConnectionAcquires(10000)
                                    .writeTimeout(Duration.ofSeconds(180))
                                    .connectionMaxIdleTime(Duration.ofSeconds(300))
                                    .connectionTimeout(Duration.ofSeconds(180))
                                    .connectionAcquisitionTimeout(Duration.ofSeconds(180))
                                    .readTimeout(Duration.ofSeconds(180)).build();
                        })
                        .build())
                .build();

        stopWatch.start();

        UploadRequest uploadRequest = UploadRequest.builder()
                .putObjectRequest(b -> b.bucket(WHATAP_AWS_BUCKET_NAME).key(WHATAP_DESTINATION_KEY))
                .addTransferListener(LoggingTransferListener.create(1))
                .requestBody(AsyncRequestBody.fromBytes(originBytes))
                .build();

        // Wait for the transfer to complete
        CompletedUpload completedUpload = transferManager.upload(uploadRequest).completionFuture().whenComplete((result, e) -> {
            if (e != null) {
                throw new RuntimeException("Failed to s3 upload file, e = " + e);
            }
        }).join();

        stopWatch.stop();
        String result = completedUpload.response().eTag();
        System.out.println("upload completed, interval: " + stopWatch.getTime() + ", result[eTag]:" + result);

I impleneted TransferListener classs. (S3PrintStackListener)

import software.amazon.awssdk.transfer.s3.progress.LoggingTransferListener;
import software.amazon.awssdk.transfer.s3.progress.TransferListener;
import software.amazon.awssdk.utils.Logger;

import java.math.BigDecimal;
import java.math.RoundingMode;
import java.util.concurrent.atomic.AtomicInteger;

import static software.amazon.awssdk.utils.StringUtils.repeat;

public class S3PrintStackListener implements TransferListener {
    private static final int DEFAULT_MAX_TICKS = 20;
    private final S3PrintStackListener.ProgressBar progressBar;

    public S3PrintStackListener(int maxTicks) {
        progressBar = new S3PrintStackListener.ProgressBar(maxTicks);
    }

    @Override
    public void transferInitiated(Context.TransferInitiated context) {
        System.out.println("Transfer initiated...");
        context.progressSnapshot().ratioTransferred().ifPresent(progressBar::update);
    }

    @Override
    public void bytesTransferred(Context.BytesTransferred context) {
        context.progressSnapshot().ratioTransferred().ifPresent(progressBar::update);
    }

    @Override
    public void transferComplete(Context.TransferComplete context) {
        context.progressSnapshot().ratioTransferred().ifPresent(progressBar::update);
        System.out.println("Transfer complete!");
    }

    @Override
    public void transferFailed(Context.TransferFailed context) {
        System.out.println("Transfer failed." + context.exception());
    }

    private static class ProgressBar {
        private final int maxTicks;
        private final AtomicInteger prevTicks = new AtomicInteger(-1);

        ProgressBar(int maxTicks) {
            this.maxTicks = maxTicks;
        }

        void update(double ratio) {
            int ticks = (int) Math.floor(ratio * maxTicks);
            if (prevTicks.getAndSet(ticks) != ticks) {
                System.out.println(String.format("|%s%s| %s",
                        repeat("=", ticks),
                        repeat(" ", maxTicks - ticks),
                        round(ratio * 100, 1) + "%"));
            }
        }

        private static double round(double value, int places) {
            BigDecimal bd = BigDecimal.valueOf(value);
            bd = bd.setScale(places, RoundingMode.FLOOR);
            return bd.doubleValue();
        }
    }
}

capture

Expected Behavior

Below code is s3 file download. It work properly.

        StopWatch stopWatch = new StopWatch();
        stopWatch.start();
        S3TransferManager transferManager = S3TransferManager.builder()
                .s3Client(S3AsyncClient.crtBuilder()
                        .region(Region.US_EAST_1)
                        .targetThroughputInGbps(30.0)
                        .minimumPartSizeInBytes(30 * 1024 * 1024L)
                        .credentialsProvider(StaticCredentialsProvider.create(AwsBasicCredentials.create(WHATAP_AWS_ACCESS_KEY_ID, WHATAP_AWS_SECRET_ACCESS_KEY)))
                        .httpConfiguration(a -> {
                            NettyNioAsyncHttpClient.builder()
                                    .maxConcurrency(500)
                                    .maxPendingConnectionAcquires(10000)
                                    .writeTimeout(Duration.ofSeconds(180))
                                    .connectionMaxIdleTime(Duration.ofSeconds(300))
                                    .connectionTimeout(Duration.ofSeconds(180))
                                    .connectionAcquisitionTimeout(Duration.ofSeconds(180))
                                    .readTimeout(Duration.ofSeconds(180)).build();
                        })
                        .build())
                .build();

        // Initiate the transfer
        Download<ResponseBytes<GetObjectResponse>> download =
                transferManager.download(DownloadRequest.builder()
                        .getObjectRequest(req -> req.bucket(WHATAP_AWS_BUCKET_NAME).key("5/myhome.com/1.0/howlong_2gb_window_monitor_file"))
                        .responseTransformer(AsyncResponseTransformer.toBytes())
                        .addTransferListener(new S3PrintStackListener(20))
                        .build());
        // Wait for the transfer to complete
        byte[] bytes = download.completionFuture().get().result().asByteArray();
        Assertions.assertNotNull(bytes);
        Assertions.assertTrue(bytes.length > 0);
        stopWatch.stop();
        System.out.println("download completed, interval: " + stopWatch.getTime());

The progress percent image is below

Current Behavior

I think this problem no needed include log

Reproduction Steps

Just watch console

@Test
    public void uploadPutObjectRequest() throws Exception {
        StopWatch stopWatch = new StopWatch();

        final String WHATAP_DESTINATION_KEY = "5/myhome.com/1.0/howlong_2gb_window_1111111gngngngn_file";

        File file = new File("/Users/junmokang/whatap/files/test_files/test10.js.map");
        byte[] originBytes = IoUtils.toByteArray(new FileInputStream(file));

        S3TransferManager transferManager = S3TransferManager.builder()
                .s3Client(S3AsyncClient.crtBuilder()
                        .region(Region.US_EAST_1)
                        .targetThroughputInGbps(30.0)
                        .minimumPartSizeInBytes(30 * 1024 * 1024L)
                        .credentialsProvider(StaticCredentialsProvider.create(AwsBasicCredentials.create(WHATAP_AWS_ACCESS_KEY_ID, WHATAP_AWS_SECRET_ACCESS_KEY)))
                        .httpConfiguration(a -> {
                            NettyNioAsyncHttpClient.builder()
                                    .maxConcurrency(500)
                                    .maxPendingConnectionAcquires(10000)
                                    .writeTimeout(Duration.ofSeconds(180))
                                    .connectionMaxIdleTime(Duration.ofSeconds(300))
                                    .connectionTimeout(Duration.ofSeconds(180))
                                    .connectionAcquisitionTimeout(Duration.ofSeconds(180))
                                    .readTimeout(Duration.ofSeconds(180)).build();
                        })
                        .build())
                .build();

        stopWatch.start();

        UploadRequest uploadRequest = UploadRequest.builder()
                .putObjectRequest(b -> b.bucket(WHATAP_AWS_BUCKET_NAME).key(WHATAP_DESTINATION_KEY))
                .addTransferListener(LoggingTransferListener.create(1))
                .requestBody(AsyncRequestBody.fromBytes(originBytes))
                .build();

        // Wait for the transfer to complete
        CompletedUpload completedUpload = transferManager.upload(uploadRequest).completionFuture().whenComplete((result, e) -> {
            if (e != null) {
                throw new RuntimeException("Failed to s3 upload file, e = " + e);
            }
        }).join();

        stopWatch.stop();
        String result = completedUpload.response().eTag();
        System.out.println("upload completed, interval: " + stopWatch.getTime() + ", result[eTag]:" + result);
    }

Possible Solution

No response

Additional Information/Context

No response

AWS Java SDK version used

software.amazon.awssdk 2.20.76, software.amazon.awssdk.s3-transfer-manager 2.20.75, software.amazon.awssdk.crt.aws-crt 0.21.17

JDK version used

OpenJDK Runtime Environment AdoptOpenJDK-11.0.11+9 (build 11.0.11+9)

Operating System and version

MacBookPro18

[JmKanmo]

둘다 정상적으로 동작하지 않습니다.

When uploading file,

Transfer initiated...
|                    | 0.0%
|=                   | 5.5%
|==                  | 10.3%
|===                 | 15.0%
|====                | 20.6%
|=====               | 25.3%
|======              | 30.1%
|=======             | 35.6%
|========            | 40.4%
|=========           | 45.1%
|==========          | 50.7%
|===========         | 55.5%
|============        | 60.2%
|=============       | 65.0%
|==============      | 70.5%
|===============     | 75.3%
|================    | 80.0%
|=================   | 85.6%
|==================  | 90.3%
|=================== | 95.1%
|====================| 100.0%

... 4min 22 sec later 

Transfer complete!

below code

  UploadFileRequest uploadFileRequest =
                    UploadFileRequest.builder()
                            .putObjectRequest(b -> b.bucket(WHATAP_AWS_BUCKET_NAME).key(WHATAP_DESTINATION_KEY))
                            .addTransferListener(LoggingTransferListener.create())
                            .source(Paths.get(filePath))
                            .build();

            stopWatch.start();
            FileUpload fileUpload = transferManager.uploadFile(uploadFileRequest);
            CompletedFileUpload uploadResult = fileUpload.completionFuture().join();

When uploading byte arrays

 UploadRequest uploadRequest = UploadRequest.builder()
                .putObjectRequest(b -> b.bucket(WHATAP_AWS_BUCKET_NAME).key(WHATAP_DESTINATION_KEY))
                .addTransferListener(LoggingTransferListener.create())
                .requestBody(AsyncRequestBody.fromBytes(originBytes))
                .build();

[JmKanmo]

It need to fix this bug.

[JmKanmo]

I think the current TransferListener is monitoring the progress of the conversion from File -> byte array.

Therefore, when uploading a byte array,
0.0% => 100% => after a while -> completed as shown above.

When uploading with Paths.get(dir), the progress is monitored as
0.0% => 32.6% => 65.3% => 98.0% => 100.0% => after a while => completed.

Users using s3 uploads/downloads want to see the full progress of the final upload to s3, not the file->to-byte-array conversion. The above matters are judged to need improvement. So, please work on improving the request.

[debora-ito]

Transferring to the Java SDK v2 repo.

I think we got a previous report of this same issue but I couldn't find it here...

[debora-ito]

Found it - #3670.

@JmKanmo I'll keep this open too, since you provided a lot of repro steps.

[leo-hydraulic]

I believe we hit this bug as well.

What we observe when uploading a file is this:
TransferListener.bytesTransferred gets called with increasing values in rapid succession:
0.0% => 32.6% => 65.3% => 98.0% => 100.0%

After we've already reached 100%, minutes pass without any calls to TransferListener.bytesTransferred.

Presumably the real transfer happens during this long pause.

Finally the transfer ends.

It seems, as someone pointed out in a previous comment, that the progress being tracked is for transferring bytes from the file into some memory buffer, not transferring them to S3.

NB: We're uploading a file, not a byte array.

[debora-ito]

Let's track this issue in #3670.

[github-actions]

This issue is now closed. Comments on closed issues are hard for our team to see.
If you need more assistance, please open a new issue that references this one.