dragonflyoss / Dragonfly

This repository has be archived and moved to the new repository https://github.com/dragonflyoss/Dragonfly2.
https://d7y.io
Apache License 2.0
6k stars 774 forks source link

bug: dfget hangs when downloading file from URL with query string (0.4.3) #810

Open kelgon opened 5 years ago

kelgon commented 5 years ago

Ⅰ. Issue Description

When downloading with dfget from a url with query string, dfget hangs forever

./dfget -u "http://foo.bar/file?1=1" -n supernode:8002

There are bunch of repeated logs in dfclient.log:

2019-08-13 15:05:50.327 INFO sign:27138-1565679945.828 : pull piece task({"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"46137344-50331647","result":503,"status":701,"pieceSize":4194304,"pieceNum":11}) result:{"code":602,"msg":"taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de: {\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep 0.980s
2019-08-13 15:05:51.310 INFO sign:27138-1565679945.828 : pull piece task({"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"46137344-50331647","result":503,"status":701,"pieceSize":4194304,"pieceNum":11}) result:{"code":602,"msg":"taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de: {\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep 1.157s

...goes on

This behavior won't happen if I remove the query string from the url:

./dfget -u "http://foo.bar/file" -n supernode:8002

NOTE: files are identical with or without the query string NOTE: only happens on supernode 0.4.3. I've tried 0.4.2 supernode 0.4.2(with dfget 0.4.3), file will be downloaded normally

Ⅱ. Describe what happened

as above

Ⅲ. Describe what you expected to happen

download should be success with or without the query string

Ⅳ. How to reproduce it (as minimally and precisely as possible)

as above

Ⅴ. Anything else we need to know?

Ⅵ. Environment:

starnop commented 5 years ago

You should define the --urlfilter or -f flag for dfget. FYI. https://github.com/dragonflyoss/Dragonfly/blob/master/dfdaemon/config/config.go#L43

kelgon commented 5 years ago

You should define the --urlfilter or -f flag for dfget. FYI. https://github.com/dragonflyoss/Dragonfly/blob/master/dfdaemon/config/config.go#L43

Yes, but what if /file?id=1 and /file?id=2 is actually two different files? query param id cannot be filtered in this case

lowzj commented 5 years ago

Could you paste the related dfget's and supernode's logs of the task? see: FAQ

kelgon commented 5 years ago

Could you paste the related dfget's and supernode's logs of the task? see: FAQ

dfclient.log

2019-08-13 15:05:45.829 INFO sign:27138-1565679945.828 : get cmd params:["./dfget" "-u" "http://fserv/1-1019651duBXAmv5?abc=123" "-s" "500M" "-n" "supernode:8002"]
2019-08-13 15:05:45.831 INFO sign:27138-1565679945.828 : get init config:{"url":"http://fserv/1-1019651duBXAmv5?abc=123","output":"/root/1-1019651duBXAmv5?abc=123","localLimit":524288000,"minRate":65536,"pattern":"p2p","node":["supernode:8002"],"clientQueueSize":6,"startTime":"2019-08-13T15:05:45.827985184+08:00","sign":"27138-1565679945.828","user":"root","workHome":"/root/.small-dragonfly","configFile":["/etc/dragonfly/dfget.yml","/etc/dragonfly.conf"]}
2019-08-13 15:05:45.831 INFO sign:27138-1565679945.828 : target file path:/root/1-1019651duBXAmv5?abc=123
2019-08-13 15:05:45.836 INFO sign:27138-1565679945.828 : runtimeVariable: {"MetaPath":"/root/.small-dragonfly/meta/host.meta","SystemDataDir":"/root/.small-dragonfly/data","DataDir":"/root/.small-dragonfly/data","RealTarget":"/root/1-1019651duBXAmv5?abc=123","TargetDir":"/root","TempTarget":"/root/dfget-27138-1565679945.828.tmp-196306968","Cid":"10.140.8.17-27138-1565679945.828","TaskURL":"http://fserv/1-1019651duBXAmv5?abc=123","TaskFileName":"1-1019651duBXAmv5?abc=123-27138-1565679945.828","LocalIP":"10.140.8.17","PeerPort":0,"FileLength":-1,"DataExpireTime":180000000000,"ServerAliveTime":300000000000}
2019-08-13 15:05:45.842 INFO sign:27138-1565679945.828 : local http result:1-1019651duBXAmv5 err:<nil>, port:33932 path:/check/
2019-08-13 15:05:45.842 WARN sign:27138-1565679945.828 : not found process on port:33932, version:0.4.3
2019-08-13 15:05:46.043 INFO sign:27138-1565679945.828 : local http result:1-1019651duBXAmv5 err:<nil>, port:33933 path:/check/
2019-08-13 15:05:46.043 WARN sign:27138-1565679945.828 : not found process on port:33933, version:0.4.3
2019-08-13 15:05:46.043 WARN sign:27138-1565679945.828 : start peer server error:invalid server on port:33933, change to CDN pattern
2019-08-13 15:05:46.044 INFO sign:27138-1565679945.828 : do register to one of [supernode:8002 supernode:8002]
2019-08-13 15:05:46.081 INFO sign:27138-1565679945.828 : do register to supernode:8002, res:{"code":200,"msg":"success","data":{"taskId":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","fileLength":52297318,"pieceSize":4194304}} error:<nil>
2019-08-13 15:05:46.081 INFO sign:27138-1565679945.828 : do register result:{"code":200,"msg":"success","data":{"taskId":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","fileLength":52297318,"pieceSize":4194304}} and cost:0.038s
2019-08-13 15:05:46.082 INFO sign:27138-1565679945.828 : downloading piece:{"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"","range":"","result":502,"status":700,"pieceSize":0,"pieceNum":0}
2019-08-13 15:05:46.084 INFO sign:27138-1565679945.828 : pull piece task({"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"","range":"","result":502,"status":700,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"clientSucCount:0,cdnSucCount:0: {\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep 1.792s
2019-08-13 15:05:47.883 ERRO sign:27138-1565679945.828 : failed to parse rate in pull rate: dial tcp4 10.140.8.17:0: connect: connection refused
2019-08-13 15:05:47.884 WARN sign:27138-1565679945.828 : request piece result:{"code":601,"data":[{"range":"0-4194303","pieceNum":0,"pieceSize":4194304,"pieceMd5":"","cid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","peerIp":"supernode","peerPort":8001,"path":"/download/ceb/ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","downLink":0},{"range":"4194304-8388607","pieceNum":1,"pieceSize":4194304,"pieceMd5":"","cid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","peerIp":"supernode","peerPort":8001,"path":"/download/ceb/ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","downLink":0},{"range":"8388608-12582911","pieceNum":2,"pieceSize":4194304,"pieceMd5":"","cid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","peerIp":"supernode","peerPort":8001,"path":"/download/ceb/ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","downLink":0},{"range":"12582912-16777215","pieceNum":3,"pieceSize":4194304,"pieceMd5":"","cid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","peerIp":"supernode","peerPort":8001,"path":"/download/ceb/ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","downLink":0}]}
2019-08-13 15:05:48.086 INFO sign:27138-1565679945.828 : downloading piece:{"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"8388608-12582911","result":503,"status":701,"pieceSize":4194304,"pieceNum":2}
2019-08-13 15:05:48.089 WARN sign:27138-1565679945.828 : request piece result:{"code":601,"data":[{"range":"16777216-20971519","pieceNum":4,"pieceSize":4194304,"pieceMd5":"","cid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","peerIp":"supernode","peerPort":8001,"path":"/download/ceb/ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","downLink":0}]}
2019-08-13 15:05:48.089 INFO sign:27138-1565679945.828 : downloading piece:{"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"12582912-16777215","result":503,"status":701,"pieceSize":4194304,"pieceNum":3}
2019-08-13 15:05:48.092 WARN sign:27138-1565679945.828 : request piece result:{"code":601,"data":[{"range":"20971520-25165823","pieceNum":5,"pieceSize":4194304,"pieceMd5":"","cid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","peerIp":"supernode","peerPort":8001,"path":"/download/ceb/ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","downLink":0}]}
2019-08-13 15:05:48.210 INFO sign:27138-1565679945.828 : downloading piece:{"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"16777216-20971519","result":503,"status":701,"pieceSize":4194304,"pieceNum":4}
2019-08-13 15:05:48.213 WARN sign:27138-1565679945.828 : request piece result:{"code":601,"data":[{"range":"25165824-29360127","pieceNum":6,"pieceSize":4194304,"pieceMd5":"","cid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","peerIp":"supernode","peerPort":8001,"path":"/download/ceb/ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","downLink":0}]}
2019-08-13 15:05:48.243 INFO sign:27138-1565679945.828 : downloading piece:{"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"20971520-25165823","result":503,"status":701,"pieceSize":4194304,"pieceNum":5}
2019-08-13 15:05:48.246 WARN sign:27138-1565679945.828 : request piece result:{"code":601,"data":[{"range":"29360128-33554431","pieceNum":7,"pieceSize":4194304,"pieceMd5":"","cid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","peerIp":"supernode","peerPort":8001,"path":"/download/ceb/ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","downLink":0}]}
2019-08-13 15:05:48.282 INFO sign:27138-1565679945.828 : downloading piece:{"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"25165824-29360127","result":503,"status":701,"pieceSize":4194304,"pieceNum":6}
2019-08-13 15:05:48.284 WARN sign:27138-1565679945.828 : request piece result:{"code":601,"data":[{"range":"33554432-37748735","pieceNum":8,"pieceSize":4194304,"pieceMd5":"","cid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","peerIp":"supernode","peerPort":8001,"path":"/download/ceb/ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","downLink":0}]}
2019-08-13 15:05:48.333 INFO sign:27138-1565679945.828 : downloading piece:{"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"29360128-33554431","result":503,"status":701,"pieceSize":4194304,"pieceNum":7}
2019-08-13 15:05:48.338 WARN sign:27138-1565679945.828 : request piece result:{"code":601,"data":[{"range":"37748736-41943039","pieceNum":9,"pieceSize":4194304,"pieceMd5":"","cid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","peerIp":"supernode","peerPort":8001,"path":"/download/ceb/ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","downLink":0}]}
2019-08-13 15:05:48.338 INFO sign:27138-1565679945.828 : downloading piece:{"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"33554432-37748735","result":503,"status":701,"pieceSize":4194304,"pieceNum":8}
2019-08-13 15:05:48.341 WARN sign:27138-1565679945.828 : request piece result:{"code":601,"data":[{"range":"41943040-46137343","pieceNum":10,"pieceSize":4194304,"pieceMd5":"","cid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","peerIp":"supernode","peerPort":8001,"path":"/download/ceb/ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","downLink":0}]}
2019-08-13 15:05:48.384 INFO sign:27138-1565679945.828 : downloading piece:{"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"37748736-41943039","result":503,"status":701,"pieceSize":4194304,"pieceNum":9}
2019-08-13 15:05:48.387 WARN sign:27138-1565679945.828 : request piece result:{"code":601,"data":[{"range":"46137344-50331647","pieceNum":11,"pieceSize":4194304,"pieceMd5":"","cid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","peerIp":"supernode","peerPort":8001,"path":"/download/ceb/ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","downLink":0}]}
2019-08-13 15:05:48.416 INFO sign:27138-1565679945.828 : downloading piece:{"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"41943040-46137343","result":503,"status":701,"pieceSize":4194304,"pieceNum":10}
2019-08-13 15:05:48.421 WARN sign:27138-1565679945.828 : request piece result:{"code":601,"data":[{"range":"50331648-54525951","pieceNum":12,"pieceSize":4194304,"pieceMd5":"","cid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","peerIp":"supernode","peerPort":8001,"path":"/download/ceb/ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","downLink":0}]}
2019-08-13 15:05:48.439 INFO sign:27138-1565679945.828 : downloading piece:{"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"46137344-50331647","result":503,"status":701,"pieceSize":4194304,"pieceNum":11}
2019-08-13 15:05:48.442 INFO sign:27138-1565679945.828 : pull piece task({"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"46137344-50331647","result":503,"status":701,"pieceSize":4194304,"pieceNum":11}) result:{"code":602,"msg":"taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de: {\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep 1.879s
2019-08-13 15:05:50.327 INFO sign:27138-1565679945.828 : pull piece task({"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"46137344-50331647","result":503,"status":701,"pieceSize":4194304,"pieceNum":11}) result:{"code":602,"msg":"taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de: {\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep 0.980s
2019-08-13 15:05:51.310 INFO sign:27138-1565679945.828 : pull piece task({"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"46137344-50331647","result":503,"status":701,"pieceSize":4194304,"pieceNum":11}) result:{"code":602,"msg":"taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de: {\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep 1.157s
2019-08-13 15:05:52.473 INFO sign:27138-1565679945.828 : pull piece task({"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"46137344-50331647","result":503,"status":701,"pieceSize":4194304,"pieceNum":11}) result:{"code":602,"msg":"taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de: {\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep 1.029s
2019-08-13 15:05:53.506 INFO sign:27138-1565679945.828 : pull piece task({"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"46137344-50331647","result":503,"status":701,"pieceSize":4194304,"pieceNum":11}) result:{"code":602,"msg":"taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de: {\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep 1.506s
2019-08-13 15:05:55.015 INFO sign:27138-1565679945.828 : pull piece task({"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"46137344-50331647","result":503,"status":701,"pieceSize":4194304,"pieceNum":11}) result:{"code":602,"msg":"taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de: {\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep 1.404s
2019-08-13 15:05:56.425 INFO sign:27138-1565679945.828 : pull piece task({"taskID":"ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","superNode":"supernode:8002","dstCid":"cdnnode:172.17.0.2~ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de","range":"46137344-50331647","result":503,"status":701,"pieceSize":4194304,"pieceNum":11}) result:{"code":602,"msg":"taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de: {\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep 1.823s

...goes on forever

app.log

2019-08-13 07:05:46.082 INFO sign:12 : success to register peer &{IP:10.140.8.17 HostName:tno_140_8_17 Port:0 Version:0.4.3}
2019-08-13 07:05:46.109 INFO sign:12 : get file length 52297318 from http client for taskID(ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de)
2019-08-13 07:05:46.109 INFO sign:12 : success to init cdn node or taskID ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de
2019-08-13 07:05:46.109 INFO sign:12 : success to start cdn trigger for taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de
2019-08-13 07:05:46.109 INFO sign:12 : taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de, detect cache breakNum: 0
2019-08-13 07:05:46.109 INFO sign:12 : reset repo for taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de
2019-08-13 07:05:46.110 INFO sign:12 : start to download for taskId(ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de) with fileUrl: http://fserv/1-1019651duBXAmv5?abc=123 header: map[] checkCode: 200
2019-08-13 07:05:46.112 INFO sign:12 : success update dfgetTask status to RUNNING with taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de clientID: 10.140.8.17-27138-1565679945.828
2019-08-13 07:05:46.123 INFO sign:12 : success to read metadata: &{TaskID:ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de URL:http://fserv/1-1019651duBXAmv5?abc=123 PieceSize:4194304 HTTPFileLen:52297318 Identifier: AccessTime:1565679946109 Interval:0 FileLength:0 Md5: RealMd5: LastModified:0 ETag: Finish:false Success:false} for taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de
2019-08-13 07:05:46.124 INFO sign:12 : success to update LastModified(Tue, 16 Jul 2019 02:21:31 GMT) and ETag(W/"52297318-1563243691107") for taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de
2019-08-13 07:05:46.626 INFO sign:12 : send all protocolContents with realFileLength(52297383) and wait for superwriter
2019-08-13 07:05:46.703 INFO sign:12 : success to read metadata: &{TaskID:ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de URL:http://fserv/1-1019651duBXAmv5?abc=123 PieceSize:4194304 HTTPFileLen:52297318 Identifier: AccessTime:1565679946109 Interval:0 FileLength:0 Md5: RealMd5: LastModified:1563243691000 ETag:W/"52297318-1563243691107" Finish:false Success:false} for taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de
2019-08-13 07:05:46.704 INFO sign:12 : success to get taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de fileLength: 52297383 realMd5: 35f90fa3800d2b8fabe02494d30beba5
2019-08-13 07:05:46.704 INFO sign:12 : success to update task cdn &{ID: CdnStatus:SUCCESS FileLength:52297383 Headers:map[] HTTPFileLength:0 Identifier: Md5: PieceSize:0 PieceTotal:0 RawURL: RealMd5:35f90fa3800d2b8fabe02494d30beba5 TaskURL:}
2019-08-13 07:05:47.910 INFO sign:12 : success update dfgetTask status to RUNNING with taskID: ceb6636133c2cf8201ffafb418d957278eadbdcbcfbb7330cd7d3e6f8bade4de clientID: 10.140.8.17-27138-1565679945.828
starnop commented 5 years ago

Could you please paste more logs of supernode. It is difficult to locate the problem for little information.

kelgon commented 5 years ago

Could you please paste more logs of supernode. It is difficult to locate the problem for little information.

I've pasted everything, there are no other supernode logs beyond. (dfclient.log continues to print the last line until I terminate dfget)

I can reproduce this bug by following steps:

  1. start a supernode 0.4.3 docker image docker run -d --name supernode --restart=always -p 8001:8001 -p 8002:8002 -v /home/admin/supernode:/home/admin/supernode a7dbe631c252 --download-port=8001
  2. start a nginx on some other machine and place a file under nginx/html
  3. download the file with dfget -u "http://.../filename?1=1" -n supernode:8002

ps: the dfget I use was from https://github.com/dragonflyoss/Dragonfly/releases/download/v0.4.3/df-client_0.4.3_linux_amd64.tar.gz