Skip to content
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

Jump to bottom

S3 transferUtility progress tracking issue #333

Closed
FilenkovMaxim opened this issue Aug 23, 2017 · 19 comments
Closed

S3 transferUtility progress tracking issue #333

FilenkovMaxim opened this issue Aug 23, 2017 · 19 comments
Labels
closing soon Issue will auto-close if there is no additional activity within 7 days. s3 Issues with the AWS Android SDK for Simple Storage Service (S3).

Comments

@FilenkovMaxim
Copy link

FilenkovMaxim commented Aug 23, 2017 •
edited
Loading

To help us solve your problem better, please answer the following list of questions.

  • What service are you using?
    TransferUtility (download)

  • In what version of SDK are you facing the problem?
    com.amazonaws:aws-android-sdk-s3:2.4.7

  • Is the issue limited to Simulators / Actual Devices?
    Actual Device (Xiaomi)

  • Can your problem be resolved if you bump to a higher version of SDK?
    no

  • Is this problem related to specific Android/OS version?
    no

  • Can you give us steps to reproduce with a minimal, complete, and verifiable example? Please include any specific network conditions that might be required to reproduce the problem.

I received not smoothy and not realistic data at onProgressChanged from TransferUtility. It finished downloading in one time after reached half size. Just jumped to 100% from 60%
It looks like this (look at the last line):
`21:58:41.0830 [main] D onProgressChanged(5, 56288708 / 111444303)

21:58:42.0750 [main] D onProgressChanged(5, 57845212 / 111444303)
21:58:43.0900 [main] D onProgressChanged(5, 59303172 / 111444303)
21:58:44.0880 [main] D onProgressChanged(5, 60466652 / 111444303)
21:58:45.0020 [main] D onProgressChanged(5, 111444303 / 111444303)`

And some times I got zero in bytesTotal argument. Not zero in first time, and then all of the calls with zero, and the last one with not zero again.
@mutablealligator
Copy link
Contributor

Hi @FilenkovMaxim,

Thanks for reporting to us.

  1. Does the non-smooth progress behavior happen for every transfer? for every file? or just in this case?
  2. Can you post the log entries when bytesTotal was zero? What is the frequency of this issue?

@FilenkovMaxim
Copy link
Author

@kvasukib hi

  1. It is at only one user on two devices (both Xiaomi), for every transfer, for every file (from our storage).
  2. At this time I havn't logs for this and cannot repeat this. If it will repeated I'll post.

@FilenkovMaxim
Copy link
Author

FilenkovMaxim commented Aug 30, 2017 •
edited
Loading

@kvasukib
Today it happens on a new device (Nexus 5, Android 6) and with different Internet provider

onProgressChanged(8, 37357164 / 111450625)
onProgressChanged(8, 38131308 / 111450625)
onProgressChanged(8, 38523500 / 111450625)
onProgressChanged(8, 111450625 / 111450625)

@FilenkovMaxim
Copy link
Author

@kvasukib hello!
Have you any news on this theme?

@mutablealligator mutablealligator added s3 Issues with the AWS Android SDK for Simple Storage Service (S3). bug Something isn't working labels Sep 12, 2017
@rohandubal rohandubal removed the bug Something isn't working label Sep 19, 2017
@rohandubal
Copy link
Contributor

Hello, what is the file type you are trying to upload? Are you using any custom headers in the request?

@FilenkovMaxim
Copy link
Author

FilenkovMaxim commented Sep 21, 2017 •
edited
Loading

@rohandubal Hello!
Firstly, it's not upload, it was download.
It could be one of two types: .zip or .aac

I use only setRegion() and not always setAccelerateModeEnabled() options.

@FilenkovMaxim
Copy link
Author

FilenkovMaxim commented Oct 12, 2017 •
edited
Loading

Hello. Any news?

Yesterday I've got again 0 in bytesTotal

it looked like this:

D: 19:57:21.5600 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 31352897 / 0)
D: 19:57:22.5710 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 33302926 / 0)
D: 19:57:23.5760 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 34728075 / 0)
D: 19:57:24.5720 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 36678104 / 0)
D: 19:57:25.5750 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 38201927 / 0)
D: 19:57:26.5860 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 40020588 / 0)
D: 19:57:27.6430 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 41527472 / 0)
D: 19:57:28.6140 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 43395174 / 0)
D: 19:57:29.6160 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 45246529 / 0)
D: 19:57:30.6180 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 47131170 / 0)
D: 19:57:31.6850 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 48654401 / 0)
D: 19:57:32.6820 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 50489409 / 0)
D: 19:57:33.6890 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 52455785 / 0)
D: 19:57:34.6930 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 54061343 / 0)
D: 19:57:35.6980 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 56003180 / 0)
D: 19:57:36.7720 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 56944927 / 0)
D: 19:57:37.7410 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 57879074 / 0)
D: 19:57:38.9950 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 59566367 / 0)
D: 19:57:39.7660 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 61041149 / 0)
D: 19:57:40.7690 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 61942010 / 0)
D: 19:57:41.7750 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 63154648 / 0)
D: 19:57:42.7850 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 65087738 / 0)
D: 19:57:43.7840 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 67004481 / 0)
D: 19:57:44.8470 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 68643325 / 0)
D: 19:57:45.8670 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 70396006 / 0)
D: 19:57:46.9500 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 71952523 / 0)
D: 19:57:47.9420 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 73558081 / 0)
D: 19:57:48.9370 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 75327701 / 0)
D: 19:57:49.9430 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 76965953 / 0)
D: 19:57:50.9480 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 78751920 / 0)
D: 19:57:51.9600 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 80161314 / 0)
D: 19:57:52.9580 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 81963628 / 0)
D: 19:57:54.1470 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 83528300 / 0)
D: 19:57:54.9130 [main] D OriginalTransfer::-#DOWNLOAD Transfer original 9847 onProgressChanged(14, 110625437 / 110625437)

My code is:

class OriginalTransfer implements com.amazonaws.mobileconnectors.s3.transferutility.TransferListener {
@OverRide
public final void onProgressChanged(int observerId, long bytesCurrent, long bytesTotal)
log.debug("{} onProgressChanged({}, {} / {})", tag, observerId, bytesCurrent, bytesTotal);
}
}

@kredden
Copy link

kredden commented Oct 19, 2017

We have been able to reproduce the first case and are working on the fix. We have not been able to reproduce the issue where the bytesTotal is 0. Are you doing more than one download at a time or just one?

@mutablealligator
Copy link
Contributor

We released 2.6.6 that fixes the progress update. Can you try upgrading to 2.6.6 and check if it works for you?

@FilenkovMaxim
Copy link
Author

@kvasukib thanks a lot. Today I'll try this.
@kredden No, no more tasks, only one. Today it was again on 2.6.5 version (

@kredden
Copy link

kredden commented Nov 16, 2017

@FilenkovMaxim Are you still having issues or did this update fix them for you?

@FilenkovMaxim
Copy link
Author

@kredden it seems to me that issue with progress was fixed. Thank you very much.
And I have no more got zero total bytes, but may be I need more time for it.

@kredden
Copy link

kredden commented Nov 27, 2017

Great! I'm going to close this issue now, if the zero issue happens again please reopen it.

@kredden kredden closed this as completed Nov 27, 2017
@mutablealligator
Copy link
Contributor

mutablealligator commented Jan 31, 2018 •
edited
Loading

Hi @FilenkovMaxim,

I was able to reproduce the issue finally. Sorry for the delayed reply.

Test case:

Start a download of 294.18 MB file.
When download reaches 40%, closed the app.
Now re-open the app, the bytesTotal is zero.
Resume the transfer.
Now bytesTotal is back to 294.18MB
Leave the download progress to 70%
Close the app again and re-open the app.
Resume the transfer.
Now bytesTotal continues to be zero till 99%
When it is about to finish the transfer, the bytesTotal gets reset to 294.18MB
Now transfer succeeds with right state and progress values.

Logs here:

01-31 14:29:20.322 8560-8625/com.amazonaws.demo.s3transferutility V/StudioProfiler: Tracking initialization took: 514710595ns
01-31 14:29:29.717 8560-8565/com.amazonaws.demo.s3transferutility I/zygote: Do partial code cache collection, code=122KB, data=78KB
01-31 14:29:29.717 8560-8565/com.amazonaws.demo.s3transferutility I/zygote: After code cache collection, code=122KB, data=78KB
01-31 14:29:29.717 8560-8565/com.amazonaws.demo.s3transferutility I/zygote: Increasing code cache capacity to 512KB
01-31 14:30:19.098 8560-9156/com.amazonaws.demo.s3transferutility D/NetworkSecurityConfig: No Network Security Config specified, using platform default
01-31 14:30:20.241 8560-8560/com.amazonaws.demo.s3transferutility D/DownloadActivity: onProgressChanged: 193, total: 308470831, current: 165506816
01-31 14:30:21.653 8560-8560/com.amazonaws.demo.s3transferutility D/DownloadActivity: onProgressChanged: 193, total: 0, current: 168141123
01-31 14:30:21.780 8560-8571/com.amazonaws.demo.s3transferutility I/zygote: Background concurrent copying GC freed 16771(2MB) AllocSpace objects, 0(0B) LOS objects, 55% free, 1215KB/2MB, paused 141us total 122.244ms
01-31 14:30:22.628 8560-8571/com.amazonaws.demo.s3transferutility I/zygote: Background concurrent copying GC freed 1915(1554KB) AllocSpace objects, 0(0B) LOS objects, 54% free, 1276KB/2MB, paused 6.366ms total 137.809ms
01-31 14:30:22.783 8560-8560/com.amazonaws.demo.s3transferutility D/DownloadActivity: onProgressChanged: 193, total: 0, current: 170247491
01-31 14:30:23.237 8560-8571/com.amazonaws.demo.s3transferutility I/zygote: Background concurrent copying GC freed 2110(1615KB) AllocSpace objects, 0(0B) LOS objects, 51% free, 1437KB/2MB, paused 272us total 116.242ms
01-31 14:30:24.049 8560-8560/com.amazonaws.demo.s3transferutility D/DownloadActivity: onProgressChanged: 193, total: 0, current: 173406507
01-31 14:30:25.146 8560-8560/com.amazonaws.demo.s3transferutility D/DownloadActivity: onProgressChanged: 193, total: 0, current: 175512875
01-31 14:30:26.780 8560-8560/com.amazonaws.demo.s3transferutility D/DownloadActivity: onProgressChanged: 193, total: 0, current: 176566595
01-31 14:30:26.812 8560-8565/com.amazonaws.demo.s3transferutility I/zygote: Do full code cache collection, code=250KB, data=163KB
01-31 14:30:26.813 8560-8565/com.amazonaws.demo.s3transferutility I/zygote: After code cache collection, code=167KB, data=110KB

01-31 14:31:11.938 8560-8571/com.amazonaws.demo.s3transferutility I/zygote: Background concurrent copying GC freed 4407(3MB) AllocSpace objects, 0(0B) LOS objects, 57% free, 1158KB/2MB, paused 8.743ms total 292.532ms
01-31 14:31:12.394 8560-8560/com.amazonaws.demo.s3transferutility D/DownloadActivity: onProgressChanged: 193, total: 0, current: 298735939
01-31 14:31:13.301 8560-8571/com.amazonaws.demo.s3transferutility I/zygote: Background concurrent copying GC freed 2066(1552KB) AllocSpace objects, 0(0B) LOS objects, 56% free, 1206KB/2MB, paused 4.416ms total 194.056ms
01-31 14:31:15.323 8560-8560/com.amazonaws.demo.s3transferutility D/DownloadActivity: onProgressChanged: 193, total: 0, current: 300842307
01-31 14:31:15.557 8560-8571/com.amazonaws.demo.s3transferutility I/zygote: Background concurrent copying GC freed 2104(1535KB) AllocSpace objects, 0(0B) LOS objects, 54% free, 1286KB/2MB, paused 10.485ms total 140.211ms
01-31 14:31:15.891 8560-8560/com.amazonaws.demo.s3transferutility D/DownloadActivity: onProgressChanged: 193, total: 0, current: 301894955
01-31 14:31:16.866 8560-8571/com.amazonaws.demo.s3transferutility I/zygote: Background concurrent copying GC freed 2150(1632KB) AllocSpace objects, 0(0B) LOS objects, 54% free, 1302KB/2MB, paused 13.075ms total 228.926ms
01-31 14:31:18.070 8560-8560/com.amazonaws.demo.s3transferutility D/DownloadActivity: onProgressChanged: 193, total: 0, current: 304001323
01-31 14:31:19.216 8560-8560/com.amazonaws.demo.s3transferutility D/DownloadActivity: onProgressChanged: 193, total: 0, current: 306107691
01-31 14:31:19.669 8560-8571/com.amazonaws.demo.s3transferutility I/zygote: Background concurrent copying GC freed 1895(1424KB) AllocSpace objects, 0(0B) LOS objects, 56% free, 1189KB/2MB, paused 111us total 129.182ms
01-31 14:31:20.186 8560-8560/com.amazonaws.demo.s3transferutility D/DownloadActivity: onProgressChanged: 193, total: 308470831, current: 308470831
01-31 14:31:20.269 8560-8560/com.amazonaws.demo.s3transferutility D/DownloadActivity: onStateChanged: 193, COMPLETED

Sorry for the inconvenience caused. We are looking into the code to spot the bug. If you have additional logs by enabling strict mode or any other test which reproduce the issue, please do attach it here.

Thanks

@mutablealligator
Copy link
Contributor

We also identified that the transfer observer after an app restart doesn't have the correct state of the transfer. We are working on to fix the internal state managed by the observer and the listener as they don't have a consistent view of the transfer record.

@FilenkovMaxim
Copy link
Author

FilenkovMaxim commented Mar 11, 2018 •
edited
Loading

Great! Please, notify me when you'll release. Then I'll be able to clean my code.

@mutablealligator
Copy link
Contributor

Thanks @FilenkovMaxim for the reply. Do you have a code snippet that you would like to share? Do you use the observer only or observer with a listener?

@stale
Copy link

stale bot commented Apr 11, 2018

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

@stale stale bot added the closing soon Issue will auto-close if there is no additional activity within 7 days. label Apr 11, 2018
@stale
Copy link

stale bot commented Apr 18, 2018

This issue has been automatically closed because of inactivity. Please open a new issue if are still encountering problems.

@stale stale bot closed this as completed Apr 18, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
closing soon Issue will auto-close if there is no additional activity within 7 days. s3 Issues with the AWS Android SDK for Simple Storage Service (S3).
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@rohandubal @FilenkovMaxim @kredden @mutablealligator