novoda / download-manager

A library that handles long-running downloads, handling the network interactions and retrying downloads automatically after failures
Apache License 2.0
483 stars 63 forks source link

Stuck waiting for network #442

Closed Hackmodford closed 6 years ago

Hackmodford commented 6 years ago

Everything was working fine in an emulator, but once I installed on a device my downloads get stuck with the status "Waiting for Network". I have changed the ConnectionType to All with the same result.

Any suggestions for what might be wrong?

Hackmodford commented 6 years ago

I'm guessing that previous batches keep their connection type setting? Because I started a different batch and it is working now.

Mecharyry commented 6 years ago

Hi @Hackmodford,

I assume you used DownloadManager.updateAllowedConnectionType(ConnectionType allowedConnectionType);?

I didn't work on this particular part of the library but I assumed that this would be per instance of the download-manager so if you update it should propagate to all existing downloads. Is this not the case @danybony @zegnus ?

Hackmodford commented 6 years ago

I am using only one instance of a download manager.

First, I noticed a crash when restarting my app. Something about initializing wasn’t working. Using “withoutNetworkPersistence” fixed this problem.

However, now when I try to download something, it seems like if it gets interrupted along the way it never continues. Some batches get stuck waiting for network.

I can provide more details once I get back to my computer if that helps.

Mecharyry commented 6 years ago

withoutNetworkPersistence? Do you mean withoutNetworkRecovery?

If you could provide us with some reproducible steps along with an expected and actual outcome we can take a look at this for you. The more detail the better really 😄

Mecharyry commented 6 years ago

I think there's generally an issue with the network recovery. Using the demo application if I start downloading assets and spam the download only over WiFi button then I see some strange behaviour. I can delete downloads and they will re-queue regardless.

Hackmodford commented 6 years ago

Sorry, yes I meant without withoutNetworkRecovery. When I originally did not have that, the app would crash the second time I launched. I just realized I never tested this change on the simulator, I am going to see if I can reproduce the issues there.

Hackmodford commented 6 years ago

Okay, I'm getting similar behavior on the simulator. I'm guessing that if I use withoutNetworkRecovery if the download gets interrupted somehow, it doesn't automatically resume?

I'm going to see if I can get the previous crash to happen on the simulator. If not, I can get you the exact error and line later today via my test device.

Hackmodford commented 6 years ago

I think I have this repeatable.

1) Start a download 2) Press the Stop button to kill the app (via android studio) 3) Restart app

Result: The download batch is stuck in the status "waiting for network"

Mecharyry commented 6 years ago

Hi @Hackmodford, I've been trying to reproduce with the above steps. Did you enable "Download only over wifi" or anything similar?

If you could attempt to reproduce any issue you are seeing with the demo that would be really handy, just to ensure there isn't something happening unique to your configuration.

zegnus commented 6 years ago

@Hackmodford

I'm guessing that if I use withoutNetworkRecovery if the download gets interrupted somehow, it doesn't automatically resume?

This is correct.

When I originally did not have that, the app would crash the second time I launched

Can you reproduce this with the demo application? If yes, can you please provide the log of the crash? We will investigate from there.

Your feedback is being really useful, thank you very much

Hackmodford commented 6 years ago

If I stop the demo app, the downloads continue. If I stop my app, the downloads stop.

zegnus commented 6 years ago

Hi @Hackmodford this is very weird, your app should behave exactly the same as in the demo application, the demo doesn't have any special permissions or shortcuts to the download manager...

Are you providing any custom implementations? Try to get back to basics and try a very simple download sample using all defaults in the download manager builder.

Hackmodford commented 6 years ago

I added a Log Handle to my app's download manager and got some error messages that might be helpful.

First, when I started my download, this is what I got:

2018-10-08 10:46:09.399 14107-14153/com.hughesmedia.big_finish E/BigFinishDownload: [pool-2-thread-1][(DownloadsFilePersistence.java:41).persistSync]  failure to persist sync file boxset=686 with status QUEUED 
2018-10-08 10:46:09.402 14107-14153/com.hughesmedia.big_finish V/BigFinishDownload: [pool-2-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: QUEUED 
2018-10-08 10:46:09.403 14107-14159/com.hughesmedia.big_finish E/BigFinishDownload: [pool-3-thread-1][(DownloadsBatchPersistence.java:189).lambda$updateStatusAsync$3]  could not update batch status QUEUED failed for boxset=686 
2018-10-08 10:46:09.408 14107-14190/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:56).download]  start sync download boxset=686, status QUEUED 
2018-10-08 10:46:09.412 14107-14190/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:175).markAsDownloadingIfNeeded]  mark boxset=686 from QUEUED to DOWNLOADING 
2018-10-08 10:46:09.412 14107-14190/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:46:09.413 14107-14190/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:67).download]  batch boxset=686 status DOWNLOADING totalBatchSize 150475400 
2018-10-08 10:46:09.416 14107-14190/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadFile.java:66).download]  persist file boxset=686, with status: DOWNLOADING 
2018-10-08 10:46:11.869 14107-14190/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:46:12.465 14107-14190/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: DOWNLOADING 

I then stopped the app which makes the download stop (there are no notifications of a download)

When I restarted the app, I got this:

2018-10-08 10:47:35.386 14275-14315/com.hughesmedia.big_finish V/BigFinishDownload: [pool-2-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: QUEUED 
2018-10-08 10:47:35.401 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:56).download]  start sync download boxset=686, status QUEUED 
2018-10-08 10:47:35.406 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:175).markAsDownloadingIfNeeded]  mark boxset=686 from QUEUED to DOWNLOADING 
2018-10-08 10:47:35.407 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:47:35.408 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:67).download]  batch boxset=686 status DOWNLOADING totalBatchSize 150475400 
2018-10-08 10:47:35.410 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:15).shouldFilterOut]  Failed filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:47:35.411 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadFile.java:66).download]  persist file boxset=686, with status: DOWNLOADING 
2018-10-08 10:47:36.820 14275-14332/com.hughesmedia.big_finish E/BigFinishDownload: [pool-4-thread-1][(NetworkFileDownloader.java:61).processResponse]  Network response code is not ok, responseCode: 416 
2018-10-08 10:47:36.824 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: WAITING_FOR_NETWORK 
2018-10-08 10:47:36.824 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:161).processNetworkError]  scheduleRecovery for batch boxset=686, status WAITING_FOR_NETWORK 
2018-10-08 10:47:36.865 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(LiteDownloadsNetworkRecoveryEnabled.java:50).scheduleRecovery]  Scheduling Network Recovery. 
2018-10-08 10:47:36.865 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:15).shouldFilterOut]  Failed filter. ID: boxset=686 Status: WAITING_FOR_NETWORK 
2018-10-08 10:47:36.866 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:90).download]  end sync download boxset=686 
2018-10-08 10:48:00.949 14275-14362/com.hughesmedia.big_finish V/BigFinishDownload: [AndroidJob-2][(LiteJobDownload.java:19).onRunJob]  LiteJobDownload run network recovery job 
2018-10-08 10:48:00.963 14275-14315/com.hughesmedia.big_finish V/BigFinishDownload: [pool-2-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: QUEUED 
2018-10-08 10:48:00.963 14275-14275/com.hughesmedia.big_finish V/BigFinishDownload: [main][(LiteJobDownload.java:18).lambda$onRunJob$0]  LiteJobDownload all jobs submitted 
2018-10-08 10:48:00.969 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:56).download]  start sync download boxset=686, status QUEUED 
2018-10-08 10:48:00.971 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:175).markAsDownloadingIfNeeded]  mark boxset=686 from QUEUED to DOWNLOADING 
2018-10-08 10:48:00.972 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:48:00.973 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:67).download]  batch boxset=686 status DOWNLOADING totalBatchSize 150475400 
2018-10-08 10:48:00.976 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:15).shouldFilterOut]  Failed filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:48:00.976 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadFile.java:66).download]  persist file boxset=686, with status: DOWNLOADING 
2018-10-08 10:48:00.984 14275-14332/com.hughesmedia.big_finish E/BigFinishDownload: [pool-4-thread-1][(NetworkFileDownloader.java:32).startDownloading]  Exception with http request 
    java.net.ProtocolException: Unexpected status line: PK��������TV"B��'��'5��DC;��������Vortex-47.pdf��t\;�0�:v�v1333333�mff��L1S���̉�bf���9s��̹ߛ�_���ڥR�T��z����5=,����4,=#���9,���5@���`�GO+��������D+����@+�G�J��LG+���D��^�����J+�����΂G��Φ���6�E����=��7#F:X�?_�,x���Y�B�a`�c�33��������0���ce��Lt���cb�����01�;���?����X�����O�/�������L����w+뿷e�c`�ۿ�e`f���q��X������b���?`��ޖ���?�23��{�����e���D��xt���!{�_6�?0G{}3K��/+V|7�w�e��U��q�e��2�S��6�y7A�?.�4�؅������脅ؙXX���޵������.��%L����N� ��.��*�����FG/����*�*(��M+gp���Yh���Ɗ�Vx����    �����͟��XXV��X���o�x�,���"f����{ZK}G����@+��kL�R��kG�wϢc�U|�������hз��2]���n�Y���p{�sr!�v���0]j���<F|A��1������B��x<*}ha`|����h�M�z�r�Hde�ؘ�����jA�~�J&wٻ�   7�5 ����(x���Ac@0�ܺ���*��E$� &klt�3oj^�d���E���Om�r0+�ݏ��0����}�=U��k>>P����O���vFr����g�=�QUU�a�I�qs|��cB�a2lP��ڷC}�j@������<j��Fm���_�܍A��P����-�IX�{���T1IS
        at okhttp3.internal.http.StatusLine.parse(StatusLine.java:69)
        at okhttp3.internal.http1.Http1Codec.readResponseHeaders(Http1Codec.java:189)
        at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:88)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
        at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
        at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:126)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
        at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:200)
        at okhttp3.RealCall.execute(RealCall.java:77)
        at com.novoda.downloadmanager.WrappedOkHttpClient.execute(WrappedOkHttpClient.java:33)
        at com.novoda.downloadmanager.NetworkFileDownloader.startDownloading(NetworkFileDownloader.java:28)
        at com.novoda.downloadmanager.DownloadFile.download(DownloadFile.java:85)
        at com.novoda.downloadmanager.DownloadBatch.download(DownloadBatch.java:80)
        at com.novoda.downloadmanager.LiteDownloadService.lambda$download$0(LiteDownloadService.java:61)
        at com.novoda.downloadmanager.-$$Lambda$LiteDownloadService$e2nbtW3ZTPVrt25dOAg1VtQGW-A.run(Unknown Source:4)
        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)
2018-10-08 10:48:00.986 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: WAITING_FOR_NETWORK 
2018-10-08 10:48:00.988 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:161).processNetworkError]  scheduleRecovery for batch boxset=686, status WAITING_FOR_NETWORK 
2018-10-08 10:48:01.022 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(LiteDownloadsNetworkRecoveryEnabled.java:50).scheduleRecovery]  Scheduling Network Recovery. 
2018-10-08 10:48:01.022 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:15).shouldFilterOut]  Failed filter. ID: boxset=686 Status: WAITING_FOR_NETWORK 
2018-10-08 10:48:01.023 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:90).download]  end sync download boxset=686 
2018-10-08 10:48:06.032 14275-14361/com.hughesmedia.big_finish V/BigFinishDownload: [AndroidJob-1][(LiteJobDownload.java:19).onRunJob]  LiteJobDownload run network recovery job 
2018-10-08 10:48:06.035 14275-14275/com.hughesmedia.big_finish V/BigFinishDownload: [main][(LiteJobDownload.java:18).lambda$onRunJob$0]  LiteJobDownload all jobs submitted 
2018-10-08 10:48:06.035 14275-14315/com.hughesmedia.big_finish V/BigFinishDownload: [pool-2-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: QUEUED 
2018-10-08 10:48:06.047 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:56).download]  start sync download boxset=686, status QUEUED 
2018-10-08 10:48:06.051 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:175).markAsDownloadingIfNeeded]  mark boxset=686 from QUEUED to DOWNLOADING 
2018-10-08 10:48:06.051 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:48:06.051 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:67).download]  batch boxset=686 status DOWNLOADING totalBatchSize 150475400 
2018-10-08 10:48:06.054 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:15).shouldFilterOut]  Failed filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:48:06.054 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadFile.java:66).download]  persist file boxset=686, with status: DOWNLOADING 
2018-10-08 10:48:07.515 14275-14332/com.hughesmedia.big_finish E/BigFinishDownload: [pool-4-thread-1][(NetworkFileDownloader.java:61).processResponse]  Network response code is not ok, responseCode: 416 
2018-10-08 10:48:07.516 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: WAITING_FOR_NETWORK 
2018-10-08 10:48:07.517 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:161).processNetworkError]  scheduleRecovery for batch boxset=686, status WAITING_FOR_NETWORK 
2018-10-08 10:48:07.542 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(LiteDownloadsNetworkRecoveryEnabled.java:50).scheduleRecovery]  Scheduling Network Recovery. 
2018-10-08 10:48:07.542 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:15).shouldFilterOut]  Failed filter. ID: boxset=686 Status: WAITING_FOR_NETWORK 
2018-10-08 10:48:07.542 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:90).download]  end sync download boxset=686 
2018-10-08 10:48:12.553 14275-14361/com.hughesmedia.big_finish V/BigFinishDownload: [AndroidJob-1][(LiteJobDownload.java:19).onRunJob]  LiteJobDownload run network recovery job 
2018-10-08 10:48:12.557 14275-14315/com.hughesmedia.big_finish V/BigFinishDownload: [pool-2-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: QUEUED 
2018-10-08 10:48:12.563 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:56).download]  start sync download boxset=686, status QUEUED 
2018-10-08 10:48:12.563 14275-14275/com.hughesmedia.big_finish V/BigFinishDownload: [main][(LiteJobDownload.java:18).lambda$onRunJob$0]  LiteJobDownload all jobs submitted 
2018-10-08 10:48:12.568 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:175).markAsDownloadingIfNeeded]  mark boxset=686 from QUEUED to DOWNLOADING 
2018-10-08 10:48:12.570 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:48:12.571 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:67).download]  batch boxset=686 status DOWNLOADING totalBatchSize 150475400 
2018-10-08 10:48:12.574 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:15).shouldFilterOut]  Failed filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:48:12.575 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadFile.java:66).download]  persist file boxset=686, with status: DOWNLOADING 
2018-10-08 10:48:12.582 14275-14332/com.hughesmedia.big_finish E/BigFinishDownload: [pool-4-thread-1][(NetworkFileDownloader.java:32).startDownloading]  Exception with http request 
    java.net.ProtocolException: Unexpected status line: PK��������TV"B��'��'5��DC;��������Vortex-47.pdf��t\;�0�:v�v1333333�mff��L1S���̉�bf���9s��̹ߛ�_���ڥR�T��z����5=,����4,=#���9,���5@���`�GO+��������D+����@+�G�J��LG+���D��^�����J+�����΂G��Φ���6�E����=��7#F:X�?_�,x���Y�B�a`�c�33��������0���ce��Lt���cb�����01�;���?����X�����O�/�������L����w+뿷e�c`�ۿ�e`f���q��X������b���?`��ޖ���?�23��{�����e���D��xt���!{�_6�?0G{}3K��/+V|7�w�e��U��q�e��2�S��6�y7A�?.�4�؅������脅ؙXX���޵������.��%L����N� ��.��*�����FG/����*�*(��M+gp���Yh���Ɗ�Vx����    �����͟��XXV��X���o�x�,���"f����{ZK}G����@+��kL�R��kG�wϢc�U|�������hз��2]���n�Y���p{�sr!�v���0]j���<F|A��1������B��x<*}ha`|����h�M�z�r�Hde�ؘ�����jA�~�J&wٻ�   7�5 ����(x���Ac@0�ܺ���*��E$� &klt�3oj^�d���E���Om�r0+�ݏ��0����}�=U��k>>P����O���vFr����g�=�QUU�a�I�qs|��cB�a2lP��ڷC}�j@������<j��Fm���_�܍A��P����-�IX�{���T1IS
        at okhttp3.internal.http.StatusLine.parse(StatusLine.java:69)
        at okhttp3.internal.http1.Http1Codec.readResponseHeaders(Http1Codec.java:189)
        at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:88)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
        at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
        at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:126)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
        at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:200)
        at okhttp3.RealCall.execute(RealCall.java:77)
        at com.novoda.downloadmanager.WrappedOkHttpClient.execute(WrappedOkHttpClient.java:33)
        at com.novoda.downloadmanager.NetworkFileDownloader.startDownloading(NetworkFileDownloader.java:28)
        at com.novoda.downloadmanager.DownloadFile.download(DownloadFile.java:85)
        at com.novoda.downloadmanager.DownloadBatch.download(DownloadBatch.java:80)
        at com.novoda.downloadmanager.LiteDownloadService.lambda$download$0(LiteDownloadService.java:61)
        at com.novoda.downloadmanager.-$$Lambda$LiteDownloadService$e2nbtW3ZTPVrt25dOAg1VtQGW-A.run(Unknown Source:4)
        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)
2018-10-08 10:48:12.583 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: WAITING_FOR_NETWORK 
2018-10-08 10:48:12.584 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:161).processNetworkError]  scheduleRecovery for batch boxset=686, status WAITING_FOR_NETWORK 
2018-10-08 10:48:12.614 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(LiteDownloadsNetworkRecoveryEnabled.java:50).scheduleRecovery]  Scheduling Network Recovery. 
2018-10-08 10:48:12.616 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:15).shouldFilterOut]  Failed filter. ID: boxset=686 Status: WAITING_FOR_NETWORK 
2018-10-08 10:48:12.618 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:90).download]  end sync download boxset=686 
2018-10-08 10:48:17.626 14275-14361/com.hughesmedia.big_finish V/BigFinishDownload: [AndroidJob-1][(LiteJobDownload.java:19).onRunJob]  LiteJobDownload run network recovery job 
2018-10-08 10:48:17.633 14275-14315/com.hughesmedia.big_finish V/BigFinishDownload: [pool-2-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: QUEUED 
2018-10-08 10:48:17.638 14275-14275/com.hughesmedia.big_finish V/BigFinishDownload: [main][(LiteJobDownload.java:18).lambda$onRunJob$0]  LiteJobDownload all jobs submitted 
2018-10-08 10:48:17.642 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:56).download]  start sync download boxset=686, status QUEUED 
2018-10-08 10:48:17.648 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:175).markAsDownloadingIfNeeded]  mark boxset=686 from QUEUED to DOWNLOADING 
2018-10-08 10:48:17.648 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:48:17.649 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:67).download]  batch boxset=686 status DOWNLOADING totalBatchSize 150475400 
2018-10-08 10:48:17.650 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:15).shouldFilterOut]  Failed filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:48:17.651 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadFile.java:66).download]  persist file boxset=686, with status: DOWNLOADING 
2018-10-08 10:48:19.240 14275-14332/com.hughesmedia.big_finish E/BigFinishDownload: [pool-4-thread-1][(NetworkFileDownloader.java:61).processResponse]  Network response code is not ok, responseCode: 416 
2018-10-08 10:48:19.242 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: WAITING_FOR_NETWORK 
2018-10-08 10:48:19.243 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:161).processNetworkError]  scheduleRecovery for batch boxset=686, status WAITING_FOR_NETWORK 
2018-10-08 10:48:19.265 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(LiteDownloadsNetworkRecoveryEnabled.java:50).scheduleRecovery]  Scheduling Network Recovery. 
2018-10-08 10:48:19.266 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:15).shouldFilterOut]  Failed filter. ID: boxset=686 Status: WAITING_FOR_NETWORK 
2018-10-08 10:48:19.266 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:90).download]  end sync download boxset=686 
2018-10-08 10:48:24.280 14275-14361/com.hughesmedia.big_finish V/BigFinishDownload: [AndroidJob-1][(LiteJobDownload.java:19).onRunJob]  LiteJobDownload run network recovery job 
2018-10-08 10:48:24.283 14275-14315/com.hughesmedia.big_finish V/BigFinishDownload: [pool-2-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: QUEUED 
2018-10-08 10:48:24.287 14275-14275/com.hughesmedia.big_finish V/BigFinishDownload: [main][(LiteJobDownload.java:18).lambda$onRunJob$0]  LiteJobDownload all jobs submitted 
2018-10-08 10:48:24.290 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:56).download]  start sync download boxset=686, status QUEUED 
2018-10-08 10:48:24.292 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:175).markAsDownloadingIfNeeded]  mark boxset=686 from QUEUED to DOWNLOADING 
2018-10-08 10:48:24.293 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:48:24.294 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:67).download]  batch boxset=686 status DOWNLOADING totalBatchSize 150475400 
2018-10-08 10:48:24.295 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:15).shouldFilterOut]  Failed filter. ID: boxset=686 Status: DOWNLOADING 
2018-10-08 10:48:24.296 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadFile.java:66).download]  persist file boxset=686, with status: DOWNLOADING 
2018-10-08 10:48:24.308 14275-14332/com.hughesmedia.big_finish E/BigFinishDownload: [pool-4-thread-1][(NetworkFileDownloader.java:32).startDownloading]  Exception with http request 
    java.net.ProtocolException: Unexpected status line: PK��������TV"B��'��'5��DC;��������Vortex-47.pdf��t\;�0�:v�v1333333�mff��L1S���̉�bf���9s��̹ߛ�_���ڥR�T��z����5=,����4,=#���9,���5@���`�GO+��������D+����@+�G�J��LG+���D��^�����J+�����΂G��Φ���6�E����=��7#F:X�?_�,x���Y�B�a`�c�33��������0���ce��Lt���cb�����01�;���?����X�����O�/�������L����w+뿷e�c`�ۿ�e`f���q��X������b���?`��ޖ���?�23��{�����e���D��xt���!{�_6�?0G{}3K��/+V|7�w�e��U��q�e��2�S��6�y7A�?.�4�؅������脅ؙXX���޵������.��%L����N� ��.��*�����FG/����*�*(��M+gp���Yh���Ɗ�Vx����    �����͟��XXV��X���o�x�,���"f����{ZK}G����@+��kL�R��kG�wϢc�U|�������hз��2]���n�Y���p{�sr!�v���0]j���<F|A��1������B��x<*}ha`|����h�M�z�r�Hde�ؘ�����jA�~�J&wٻ�   7�5 ����(x���Ac@0�ܺ���*��E$� &klt�3oj^�d���E���Om�r0+�ݏ��0����}�=U��k>>P����O���vFr����g�=�QUU�a�I�qs|��cB�a2lP��ڷC}�j@������<j��Fm���_�܍A��P����-�IX�{���T1IS
        at okhttp3.internal.http.StatusLine.parse(StatusLine.java:69)
        at okhttp3.internal.http1.Http1Codec.readResponseHeaders(Http1Codec.java:189)
        at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:88)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
        at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
        at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:126)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
        at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:200)
        at okhttp3.RealCall.execute(RealCall.java:77)
        at com.novoda.downloadmanager.WrappedOkHttpClient.execute(WrappedOkHttpClient.java:33)
        at com.novoda.downloadmanager.NetworkFileDownloader.startDownloading(NetworkFileDownloader.java:28)
        at com.novoda.downloadmanager.DownloadFile.download(DownloadFile.java:85)
        at com.novoda.downloadmanager.DownloadBatch.download(DownloadBatch.java:80)
        at com.novoda.downloadmanager.LiteDownloadService.lambda$download$0(LiteDownloadService.java:61)
        at com.novoda.downloadmanager.-$$Lambda$LiteDownloadService$e2nbtW3ZTPVrt25dOAg1VtQGW-A.run(Unknown Source:4)
        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)
2018-10-08 10:48:24.308 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:22).shouldFilterOut]  Passes filter. ID: boxset=686 Status: WAITING_FOR_NETWORK 
2018-10-08 10:48:24.309 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:161).processNetworkError]  scheduleRecovery for batch boxset=686, status WAITING_FOR_NETWORK 
2018-10-08 10:48:24.334 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(LiteDownloadsNetworkRecoveryEnabled.java:50).scheduleRecovery]  Scheduling Network Recovery. 
2018-10-08 10:48:24.334 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatchStatusFilter.java:15).shouldFilterOut]  Failed filter. ID: boxset=686 Status: WAITING_FOR_NETWORK 
2018-10-08 10:48:24.336 14275-14332/com.hughesmedia.big_finish V/BigFinishDownload: [pool-4-thread-1][(DownloadBatch.java:90).download]  end sync download boxset=686 

Does that provide any clues?

Hackmodford commented 6 years ago

I will be asking the team that develops the API I am using to see if there's any clues they can provide. It seems like when the library is trying to resume the download, the API returns HTTP Code 416.

Side question, should the library be in a loop in this scenario? It should eventually stop trying, right?

Hackmodford commented 6 years ago

I just tried downloading my file via the demo application. When I do this I get the same result as my application.

Hackmodford commented 6 years ago

I just tested downloading with a range request using Insomnia. The partial download worked correctly, this leads me to believe there is a bug in the download manager.

Hackmodford commented 6 years ago

Using the demo application, pausing and resuming works fine. It seems like it's just if I kill the app and start it up again that I get the 416 error. I just tried it again and I get the same behavior as killing the app.

Mecharyry commented 6 years ago

@Hackmodford sorry can I just clarify that you've run the vanilla demo, without touching any of the code and you are seeing this issue? You are running this on an emulator or a specific device?

Hackmodford commented 6 years ago

@Mecharyry Correct. I am using the vanilla demo, and have only changed the file that it downloads. If I pause the download and try to resume, I get the 416 error. I will provide a url you can use for testing this later.

Unfortunately I wasn’t able to get any useful information from the server logs.

Hackmodford commented 6 years ago

Here is a url that can be used for testing.

https://www.bigfinish.com/api/downloadab/895/get/?token=aa149703e92f683dc779da021d57b148266567a3

Mecharyry commented 6 years ago

Thanks for providing that @Hackmodford, I'll try and take a look at this as soon as I am able.

Mecharyry commented 6 years ago

Hi @Hackmodford I've taken a look at the demo using the above url. I can see that it does indeed fail when triggering a pause and resume. I'm getting a 416 as you have said, my next question is, does this API support the Range header? I'm happy to take a look if you can forward me to any documentation. If the API does not support the range header then this would be why this fails, you need this to resume a download.

I'm sorry this has taken me some time to look into and I hope we can help you get this sorted soon!

Hackmodford commented 6 years ago

Hi @Mecharyry I'm not the developer of the API and it is a private API so there is no documentation I can really provide. However, I'm fairly certain it does support this. The response header claims it does support the range header and I am able to resume/pause downloads in the iOS version of my app as well as being able to resume the download using a REST client such as insomnia.

Mecharyry commented 6 years ago

Ah ok, it's annoying that the API is private. There could be something wrong with the ranges we are supplying for the file. I'll try and take a look again today and see if I can find anything else. Do you have a request with a byte range that you have seen work? The whole request including headers would be really useful.

For reference: https://www.bigfinish.com/api/downloadab/895/get/?token=aa149703e92f683dc779da021d57b148266567a3

Hackmodford commented 6 years ago

The team in charge of the API got back to me with some more info!

We’ve discovered that the API does support the Range header.

The code we’re using can be seen here:

https://github.com/cakephp/cakephp/blob/2.x/lib/Cake/Network/CakeResponse.php

Line 1418

This is the code that is giving the 416 response.

We tested it using the Postman software - (excellent tool https://www.getpostman.com/) and the URL you supplied:

https://www.bigfinish.com/api/downloadab/186/get/?token=edd0248fd045b89d4306e09f10990a14316e2b08

If we use Postman and send a Range header Range: bytes=5185536-124940923 we get a 416 response.

If we decrease the end number from 124940923 to 124940922 (1 less) we can see that the Range header works.

We think that this is an indexing by 0/1 issue. We think that you’ll still get the whole file using the smaller number.

We’d prefer not to modify the core PHP framework if we can help it. Can you see if this will work for you?

I hope that this helps.

zegnus commented 6 years ago

hi @Hackmodford, I think that by the specs https://datatracker.ietf.org/doc/rfc7233/?include_text=1 we should be requesting size-1. We'll some tests and feedback when finished.

Hackmodford commented 6 years ago

@zegnus That’s excellent news! If this gets updated, I will, of course, be glad to test it in my app.

Hackmodford commented 6 years ago

I cloned the develop branch on my machine and tested downloading via the demo app. So far so good!

Once there is a release build with this change ready I will test in my actual app.

Mecharyry commented 6 years ago

Hi @Hackmodford, just to let you know that we have released a version that should resolve your issue! Let us know if you have any other questions 😄

Hackmodford commented 6 years ago

@Mecharyry Just wanted to let you know, it is working in my app. Thanks for the help!