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.

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

断点续传进度有误 #39

Closed
qianshengta opened this issue Apr 23, 2018 · 19 comments
Closed

断点续传进度有误 #39

qianshengta opened this issue Apr 23, 2018 · 19 comments
Labels
Milestone

Comments

@qianshengta
Copy link

在demo的SingleDownload中,我下载了百分之五六十,然后点击取消,关掉app,刷掉进程。然后重新进去,个别时候没有进度需要重新下载,个别时候进度只有百分之二三十左右,但是我退出之前显示的进度确实百分之五六十。不知道这个问题是出在哪里。

@HeyAragon
Copy link

HeyAragon commented Apr 23, 2018

有些资源下载时候(http://uCQMz.zjgyxz.hwm6b6.cn/vp/yx_ljun1/yongbingduijue.apk ),下载完之前,关掉app,之后再次进入,通过StatusUtil.getCurrentInfo()获取不到断点信息,而且status会显示completed、但是人物并没有下载完成。还有下载工程中希望像filedownloader一样用.temp给临时文件命名~~

@qianshengta
Copy link
Author

找不到页面.....@HeyAragon

@Jacksgong
Copy link
Collaborator

Jacksgong commented Apr 23, 2018

@HeyAragon 你的问题,提新的issue,具体我没有看明白。

@qianshengta 你的问题,你留意下日志。

前言

当你点击取消的时候,会有两个异步线程分别做了两件事情:

  1. 强制刷新缓存中的下载数据到文件系统
  2. 强制同步缓存中的进度数据到数据库(默认考虑你已经引了sqlite库)

image

根据你的描述,我这边反复测试都没有复现,由于是非常极端的情况。

不过根据理论分析你的问题是很有可能因为以下原因导致的,其中一个是bug,另外一个则不是

原因一,极端情况非BUG

如果一暂停完成,立马杀了对应的进程,则两个异步线程还未完成,则断点数据没有被同步进数据库,下次启动只是从最近一次同步的断点开始。

原因二,极端BUG

该情况是,由于目前其实两个线程只有启动有先后顺序,但是是在两个不同池子里的不同线程,实际运行没有先后顺序,并且是在数据库还未进行过首次常规进度同步的前提下(默认是任务启动后1.5s执行),导致: 同步进度到数据库的job在刷新缓存到文件系统的job之前,此时,由于RemitDatabase不再递交其任务到数据库,导致此时的进度只存在于缓存。

但是这个理论概率是很低的:1. 刷新缓存到文件系统的job启动时间 早于 同步进度到数据库系统的job的启动时间;2. 刷新缓存文件系统的job通常会快于这块的数据库操作;3. 如果任务启动大于1.5s(默认),那么此时数据库便是完全开放刷新的,因此这种情况便不会将进度只存储在缓存。

不过这个极端BUG依然会在1.0.2-SNAPSHOT中修复

以上两个原因都可以一定程度通过日志进行验证

需要特别留意的是在全程操作中,是否有sync info with id的日志(此日志说明是否有做数据库同步):

  • 如果有便有做过同步 ---> 但是如果在cancel之前便已经有做过同步,此时便要关注OutputStream sync success是否启动的所有断点都完成OutputStream sync success日志输出,如果没有便是原因一所描述的,如果有就一定完成了同步;如果是在cancel之后完成的同步,那么也是肯定完成了同步
  • 如果没有便没有做过同步 ---> 这种情况便是原因二所描述的

介于你描述的这么好复现,还是希望你能提供下日志进行对原因的验证,如果你无法从日志中得到验证,麻烦适配Debug后,复现然后将全程的日志,截图贴出来,谢谢。

@Jacksgong Jacksgong added this to the 1.0.2 milestone Apr 23, 2018
@qianshengta
Copy link
Author

@Jacksgong 好的 日志的话我明天上班的时候去收集下。
不知道你有没有试过第一次下载,带一定程度,然后停止退出刷掉进程,然后进入开始,继续停止退出刷掉进程。我今晚试过好几次,大多数情况都是我重新进入后的进度比我退出前的进度要短上一节(最起码进度条上是这样反馈的,至于文件上是不是这样还有待测试)。我不知道是文件下载上有所错误还是进度条上显示的错误。
不管怎么样,多谢你的分享和解答,万分感谢。

@Jacksgong
Copy link
Collaborator

Jacksgong commented Apr 23, 2018

我反复测试了多次,这块没有问题,还是希望你给下日志吧。

反复测试其中一个小案例

在有进度的情况下,启动,停止,刷掉进程:

image

再启动,进度一致:

image

再杀掉进程:

image

再启动,进度一致:

image

@qianshengta
Copy link
Author

@Jacksgong
我每次都只下载大概百分之一二十左右,然后退出刷掉重进,进度条都只有一点点,如果是在百分之六七十的时候退出的话没进入的时候进度条会有百分之四五十这样子的。
第一次暂停
pause1
第一次重新开始
restart1
第二次暂停(之前下载的进度都丢失了,相当于重新下载了)
pause2
第二次重新开始
restart2
第一次退出重进后的界面,进度条只有一点
interface

@Jacksgong
Copy link
Collaborator

Jacksgong commented Apr 23, 2018

@qianshengta 可否有办法提供全程完整的日志,哪怕不要截图,就提供文本。这样我不是很清楚,首先你第一次暂停与第一次重新开始都没有问题,然后你第二次暂停的时候,该次停止时的进度比启动的时的进度还少?进度还回退了,我没有看明白?

@qianshengta
Copy link
Author

好的,我明天得时候提供下完整的log。
准确的来说,我第一次开始任务的时候,进度到百分之十几的时候暂停,然后重新启动app,这时候界面上的进度就只有那么一点点了,然后我再次点击开始,依然是进度到百分之十几的时候暂停(就是第二次暂停),然后退出重进,这时候进度条还是只有一点点。再次点击开始(第二次开始),还是重新开始下载,之前的进度都丢课。

@qianshengta
Copy link
Author

@Jacksgong 您也小早点睡吧,明天再研究吧

@qianshengta
Copy link
Author

@Jacksgong
第一次下载,从进入页面到退出(进度大约在百分之十几时暂停)
start2pause1
第二次下载,继续之前,从进入页面到退出(进度还是在大约百分之十几时暂停)
start2pause2
第三次下载,依然继续之前的,从进入界面到退出(进度还是在大约百分之十几时暂停)
start2pause3
以上每次重新进入页面后,进度条都只有一点点,好像没有进度一样。

卸载app后从新测试,这次下载到大约百分之四五十的时候暂停
第一次下载,进入页面到退出(进度大约百分之四五十时暂停)
start2pause4
第二次下载,继续之前,从进入页面到退出(进度还是在大约百分之四五十时暂停)
start2pause5
第三次下载,继续之前,从进入页面到退出(进度还是大约在百分之四五十时暂停)
start2pause6
以上测试,每次在进度到百分之四五十时暂停退出,下次重新进入后,进度条比退出前短了一截,大约百分之十左右

@Jacksgong
Copy link
Collaborator

Jacksgong commented Apr 24, 2018

@qianshengta 你的日志并没有适配okcat,因此截图出来可读性很差,我现在手头有点事情,你如果方便的话,这段时间,你可否直接将连续完整的日志,直接复制粘贴为文本发送给我,我手头一点事情忙完,我本地通过用okcat文本去解析看,这样提高效率。

@qianshengta
Copy link
Author

@Jacksgong
好的 我下午出差不在公司 等晚上回去的时候我在发一份集成了Logger的日志,这种可读性高多了,再复制一份txt的。
我早上做测试的时候可能发现了其中的问题,之前进度有问题的测试的时候,下载速度都是5/6M的下载速度,基本上每次进度都有问题,但是刚刚在外面的时候,我用自己的手机热点下载,速度就一两百KB,进度都是正确的,来回测试了几次都没问题。您看问题是不是出在这里?

@Jacksgong
Copy link
Collaborator

@qianshengta 好的,等你的日志,不过以防万一,最好也提供一份日志原件,我下午有点东西也要处理下。

P.S. 我家的网速很快,我在家里测试也都是几十兆每秒的速度,并无该问题(我家是电信500M的光纤..)

@qianshengta
Copy link
Author

qianshengta commented Apr 24, 2018

@Jacksgong
我给你igzhenjie@gmail.com邮箱发了日志了,一个四组数据 截图两组,txt两组,你看收到没。
我这测试还是那样,回到公司后,下载速度达到4/5M后,同样的问题又出现了。在我这里是这样的,下载速度就一两百kb的时候没问题的,在下载速度达到4/5M的时候问题又回来了。应该也不是wifi的问题,我在家的时候速度5/6M的时候也是同样的问题

@Jacksgong
Copy link
Collaborator

收到了,我一会儿看下,下次可以直接在Issue中上传,直接附件拉到评论框就可以了。

@Jacksgong
Copy link
Collaborator

你这个日志的颜色可读性太差了,再次建议使用okcat,我这边不得不再根据你提供的日志文件的日志格式编写的okcat.yml(解压缩后使用): okcat.yml.zip

以下所有数据皆来自你给的日志文件:

"60%"的两份文件:

image

image

以上两个看起来没有任何问题。

"15%"的两份文件:

image

image

"15%"的这两个日志文件,第一个直接释放了文件锁,而没有完成刷新缓存到文件系统的日志,如果你的日志是完整的,那么这里我猜测极大的可能是文件系统存在问题,刷新失败导致。


但是这里的失败日志被我ignored了,这里之前被我忽略的原因是如果在持续的下载过程中,这次失败,4096kb后会再次重试,因此不打紧,但是如果是这种最后一次刷新的场景,这个日志是可以说明问题的,因此我在1.0.2-SNAPSHOT上加了日志。

请你引用1.0.2-SNAPSHOT版本(引用参考这里),然后再次验证(如果你之前就是引了这个snapshot版本,你需要确认下你本地snapshot缓存是否刷新),看看是否存在内容包含OutputStream flush and sync data to filesystem failed的日志,如果是,就验证了刷新到文件系统失败的问题。请验证之。


而如果是最后同步到文件系统失败,因此该进度在进程被杀了以后,由于无法有效的同步到文件系统而丢失,这个问题便相对比较无解,而下次启动没有使用上一次进程中的最后的进度,也是正确的做法,因为真正文件系统中的进度并非上一次进程的最后的进度。

Jacksgong added a commit that referenced this issue Apr 24, 2018
…lesystem failed, because on the final time it is significant

refs #39
@qianshengta
Copy link
Author

qianshengta commented Apr 25, 2018

@Jacksgong
我昨天晚上弄了一晚上的适配okcat,最终还是没弄成,不懂python,根本不知道怎么安装o(╥﹏╥)o。
还有60%我从手机上观察到的现象是,重新进入后的进度条比我暂停退出前的进度条短了一截。
最新的验证了之后,的确有OutputStream flush and sync data to filesystem failed日志的打印,
4bp j1 qg sl7106 s6o l
这个问题跟手机又关系吗?我两个测试急一个红米一个中兴的老型号的机子,都有这个问题

@Jacksgong
Copy link
Collaborator

Jacksgong commented Apr 25, 2018

@qianshengta ok,看到这个日志我就知道原因,可能确实是在部分机型上面比较容易出现,如果都是BufferedOutputStream is closed,那么这个问题可以很确定是在 1.0.0上面没有,在1.0.1上面引入的。这个问题,我尽快修下。

P.S. 如果是mac os的话,正常来说安装okcat应该是很简单的,只要安装homebrew,然后通过homebrew安装python,然后再通过pythoneasy_install安装pip;最后用pip安装okcat就可以了,参考这里

@Jacksgong Jacksgong added bug and removed need-info labels Apr 25, 2018
Jacksgong added a commit that referenced this issue Apr 26, 2018
…ith output-stream and ensure close output-stream after the last operation for output-stream

refs #39
@Jacksgong
Copy link
Collaborator

评论中提到的所有问题,都已经在1.0.2-SNAPSHOT中修复了,你可以在SNAPSHOT中进行验证。

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants