Aws-sdk-android: S3 TransferUtility Upload part interrupted: time out and socket is closed

[bahiamartins]

Hello everyone,

I have an app in which uploads videos to S3 using TransferUtility.
It works in most cases, but in Xiomi MI 8 Lite, it crashes.

I thought it was a max size issue, but is not.

I appreciate any suggestions on how to fix it.

SDK version

    implementation 'com.amazonaws:aws-android-sdk-core:2.16.5'
    implementation 'com.amazonaws:aws-android-sdk-s3:2.16.5'
    implementation 'com.amazonaws:aws-android-sdk-cognito:2.16.5'

Here is my code:

private void uploadFile() {

        spinProgress.setVisibility(View.VISIBLE);

        CognitoCachingCredentialsProvider credentialsProvider = new CognitoCachingCredentialsProvider(
                getApplicationContext(),
                "XXX",
                Regions.US_EAST_1 // Region
        );

        // get file to upload
        prepend = "android-" + interviewId + "-" + String.valueOf(questionId) + ".mp4";

        videoToUpload = CamRecordActivity.getOutputMediaFile(
                interviewId,
                questionId,
                this
        );

        TransferNetworkLossHandler.getInstance(getApplicationContext());
        //TransferNetworkLossHandler.getInstance(getApplicationContext()).onReceive(getApplicationContext(), new Intent().setAction(ConnectivityManager.CONNECTIVITY_ACTION));

        AmazonS3Client s3 = new AmazonS3Client(credentialsProvider);
        s3.setRegion(Region.getRegion(Regions.US_EAST_1));

        final TransferUtility transferUtility = new TransferUtility(s3, getApplicationContext());

        // connection timeout
        ClientConfiguration clientConfiguration = new ClientConfiguration();
        // 30 seconds
        clientConfiguration.setConnectionTimeout(30000);
        // 5 min
        clientConfiguration.setSocketTimeout(300000);

        final TransferObserver transferObserver = transferUtility.upload(
                "mobvideosappin",     /* The bucket to upload to */
                prepend,    /* The key for the uploaded object */
                videoToUpload        /* The file where the data to upload exists */
        );

        transferObserver.setTransferListener(new TransferListener(){

            @Override
            public void onStateChanged(int id, TransferState state) {
                Log.i("STATE: ", String.valueOf(state));

                if (state.equals(TransferState.COMPLETED)) {
                    Log.i("DONE: ", String.valueOf(state));
                    spinProgress.setVisibility(View.INVISIBLE);
                    postAnswer.start();
                    transferUtility.cancel(id);
                }

                if (state.equals(TransferState.FAILED)) {
                    showToast(getString(R.string.tryagain));

                    Thread th = new Thread((Runnable) transferUtility.resume(id));
                    th.start();

                    //finish();
                    //startActivity(getIntent());
                }

                if (state.equals(TransferState.WAITING) || state.equals(TransferState.WAITING_FOR_NETWORK)) {
                    showToast(getString(R.string.waiting));
                }

                if (state.equals(TransferState.CANCELED)) {
                    showToast(getString(R.string.tryagain));

                    finish();
                    startActivity(getIntent());
                }

            }

            @Override
            public void onProgressChanged(int id, long bytesCurrent, long bytesTotal) {

                Log.i("BYTES", String.valueOf(transferObserver.getBytesTransferred()));

                float _percent = ((float)bytesCurrent/(float)bytesTotal)*100.0f;
                final int percentage = (int) _percent;

                mProgress.setMax(100);
                mProgress.setProgress(percentage);
                textProgress.setText(String.valueOf(percentage) + "%");

            }

            @Override
            public void onError(int id, Exception ex) {
                textProgress.setText(getString(R.string.tryagain));

                ex.printStackTrace();

                finish();
                startActivity(getIntent());

            }

        });


    }

And here is the log:

I/BYTES: 16777216
2019-12-20 17:20:46.053 3272-3937/com.jobconvo.entrevistanew E/UploadPartTask: Upload part interrupted: com.amazonaws.AmazonClientException: Unable to execute HTTP request: timeout
2019-12-20 17:20:46.056 3272-3272/com.jobconvo.entrevistanew I/BYTES: 17190538

...

I/BYTES: 8388608
2019-12-20 17:23:54.273 4672-4994/com.jobconvo.entrevistanew E/UploadPartTask: Upload part interrupted: com.amazonaws.AmazonClientException: Unable to execute HTTP request: timeout
2019-12-20 17:23:54.286 4672-4672/com.jobconvo.entrevistanew I/BYTES: 8696079
2019-12-20 17:23:54.302 4672-4994/com.jobconvo.entrevistanew E/UploadPartTask: Encountered error uploading part 
    com.amazonaws.AmazonClientException: Unable to execute HTTP request: timeout
        at com.amazonaws.http.AmazonHttpClient.executeHelper(AmazonHttpClient.java:441)
        at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:212)
        at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:4913)
        at com.amazonaws.services.s3.AmazonS3Client.uploadPart(AmazonS3Client.java:3887)
        at com.amazonaws.mobileconnectors.s3.transferutility.UploadPartTask.call(UploadPartTask.java:60)
        at com.amazonaws.mobileconnectors.s3.transferutility.UploadPartTask.call(UploadPartTask.java:30)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:764)
     Caused by: java.net.SocketTimeoutException: timeout
        at com.android.okhttp.okio.Okio$3.newTimeoutException(Okio.java:212)
        at com.android.okhttp.okio.AsyncTimeout.exit(AsyncTimeout.java:261)
        at com.android.okhttp.okio.AsyncTimeout$2.read(AsyncTimeout.java:215)
        at com.android.okhttp.okio.RealBufferedSource.indexOf(RealBufferedSource.java:306)
        at com.android.okhttp.okio.RealBufferedSource.indexOf(RealBufferedSource.java:300)
        at com.android.okhttp.okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:196)
        at com.android.okhttp.internal.http.Http1xStream.readResponse(Http1xStream.java:186)
        at com.android.okhttp.internal.http.Http1xStream.readResponseHeaders(Http1xStream.java:127)
        at com.android.okhttp.internal.http.HttpEngine.readNetworkResponse(HttpEngine.java:737)
        at com.android.okhttp.internal.http.HttpEngine.readResponse(HttpEngine.java:609)
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:471)
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getResponse(HttpURLConnectionImpl.java:407)
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getResponseMessage(HttpURLConnectionImpl.java:534)
        at com.android.okhttp.internal.huc.DelegatingHttpsURLConnection.getResponseMessage(DelegatingHttpsURLConnection.java:109)
        at com.android.okhttp.internal.huc.HttpsURLConnectionImpl.getResponseMessage(HttpsURLConnectionImpl.java:26)
        at com.amazonaws.http.UrlHttpClient.createHttpResponse(UrlHttpClient.java:92)
        at com.amazonaws.http.UrlHttpClient.execute(UrlHttpClient.java:85)
        at com.amazonaws.http.AmazonHttpClient.executeHelper(AmazonHttpClient.java:371)
        at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:212) 
        at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:4913) 
        at com.amazonaws.services.s3.AmazonS3Client.uploadPart(AmazonS3Client.java:3887) 
        at com.amazonaws.mobileconnectors.s3.transferutility.UploadPartTask.call(UploadPartTask.java:60) 
        at com.amazonaws.mobileconnectors.s3.transferutility.UploadPartTask.call(UploadPartTask.java:30) 
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) 
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) 
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) 
        at java.lang.Thread.run(Thread.java:764) 
     Caused by: java.net.SocketException: socket is closed
        at com.android.org.conscrypt.ConscryptFileDescriptorSocket$SSLInputStream.read(ConscryptFileDescriptorSocket.java:551)
        at com.android.okhttp.okio.Okio$2.read(Okio.java:136)
        at com.android.okhttp.okio.AsyncTimeout$2.read(AsyncTimeout.java:211)
        at com.android.okhttp.okio.RealBufferedSource.indexOf(RealBufferedSource.java:306) 
        at com.android.okhttp.okio.RealBufferedSource.indexOf(RealBufferedSource.java:300) 
        at com.android.okhttp.okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:196) 
        at com.android.okhttp.internal.http.Http1xStream.readResponse(Http1xStream.java:186) 
        at com.android.okhttp.internal.http.Http1xStream.readResponseHeaders(Http1xStream.java:127) 
        at com.android.okhttp.internal.http.HttpEngine.readNetworkResponse(HttpEngine.java:737) 
        at com.android.okhttp.internal.http.HttpEngine.readResponse(HttpEngine.java:609) 
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:471) 
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getResponse(HttpURLConnectionImpl.java:407) 
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getResponseMessage(HttpURLConnectionImpl.java:534) 
        at com.android.okhttp.internal.huc.DelegatingHttpsURLConnection.getResponseMessage(DelegatingHttpsURLConnection.java:109) 
        at com.android.okhttp.internal.huc.HttpsURLConnectionImpl.getResponseMessage(HttpsURLConnectionImpl.java:26) 
        at com.amazonaws.http.UrlHttpClient.createHttpResponse(UrlHttpClient.java:92) 
        at com.amazonaws.http.UrlHttpClient.execute(UrlHttpClient.java:85) 
        at com.amazonaws.http.AmazonHttpClient.executeHelper(AmazonHttpClient.java:371) 
        at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:212) 
        at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:4913) 
        at com.amazonaws.services.s3.AmazonS3Client.uploadPart(AmazonS3Client.java:3887) 
        at com.amazonaws.mobileconnectors.s3.transferutility.UploadPartTask.call(UploadPartTask.java:60) 
        at com.amazonaws.mobileconnectors.s3.transferutility.UploadPartTask.call(UploadPartTask.java:30) 
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) 
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) 
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) 
        at java.lang.Thread.run(Thread.java:764) 

[TrekSoft]

Hey, did you follow the instructions in the documentation for setting up TransferService?

https://aws-amplify.github.io/docs/sdk/android/storage

[desokroshan]

Closing due to inactivity.

[julo15]

~i just painfully dealt with and finally found the workaround for this issue.~

~I've seen various reports of this, and the solution/workaround is to start the TransferService service from your application's onCreate function. This solution, for some reason, was not working for me.~

~I finally found why: https://github.com/awslabs/aws-sdk-android-samples/pull/337
On Android O and up, you need to start the service as a foreground service. I had to copy these lines in their entirety before the issue finally went away.~

~@TrekSoft @desokroshan can the Android S3 getting started instructions be updated to reflect this?~

I take the above back. I can't seem to get this working, besides exactly one time where things did work.

The situation I'm in is this:

• Uploading tiny files works fine
• Uploading larger files (~10MB) seems to fail after a fixed period of time, about 20 seconds, with the same 'socket is closed' error that @bahiamartins reported. The call stack looks identical to mine
• I'm using a Samsung S20

@TrekSoft what is particular in the documentation should I make sure I try? I'm incredibly stumped right now. I'll also mention that I have, a couple years ago, successfully used the TransferUtility on Android without this issue, so I have some reasonable familiarity with the library.

[TrekSoft]

Hey, sorry to hear about the trouble. For new development, we’re recommending the Storage category in the Amplify libraries. We currently support both products and you may continue to use the old S3TransferUtility if Amplify doesn’t cover your use case. However, I think you'll find it much easier and it sets up everything properly for you: https://docs.amplify.aws/lib/storage/getting-started/q/platform/android

[julo15]

Thanks @TrekSoft . One feature that we need is specifying different BasicSessionCredentials into each upload call that we make; I wasn't sure if that was supported by the new Amplify Storage library.

Is the Storage implementation based on TransferUtility/TransferService, or is it a different implementation altogether?

[julo15]

So, for now, I have found that setting the socket timeout to 0 (aka infinity) seems to be working as a workaround for me.

            val config = ClientConfiguration()
            config.socketTimeout = 0
            client = AmazonS3Client(awsCredentials, Region.getRegion(region), config)

@TrekSoft assuming Storage supports the case I mention above, I can evaluate switching over to it a bit later on.

Wanted to share these observations on my specific repro. I did some investigation using Charles proxy to better understand what was happening. The socket exception was consistently getting thrown at approximately the same time as when the first http PUT succeeds (of the multi-part upload). "First" in this case doesn't mean partNumber = 1; it means whichever was fastest to complete. So, basically each time, I would see one of the PUTs succeed (200 OK), and then my breakpoint on the thrown socket exception hit. This would be after approximately 13 seconds, which is actually below the default socket timeout of 15 seconds.

I would usually only see one socket exception thrown, but sometimes there would be several (up to 10, which makes sense since there are at most 10 http requests happening at a given time).

It makes me think that something is causing the socket to prematurely close. I've only tested with 2 device: Samsung S20 and the Android emulator, and this issue only happens on the Samsung.

I'm not sure why setting the socket timeout to 0 makes the problem disappear.

[TrekSoft]

Thanks very much for that info. As you asked about, Amplify Storage currently uses TransferUtility under the hood so what you could do is get a reference to the AmazonS3Client escape hatch and make your calls using the low level functionality with it all being setup and configured nicely with Amplify: https://docs.amplify.aws/lib/storage/escapehatch/q/platform/android