search

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

dfget download speed is very slow #1360

Closed 111wang222 closed 4 years ago

111wang222 commented 4 years ago

Question

  1. there are: 1 source 3 supernodes and 50 nodes source supernode with 1Gbps network node download speed ,maybe 5~100 Mbps dfget version:0.3.0

  2. supernode supernode start with: java -Dsupernode.baseHome=/data0/dfhome -Dsupernode.totalLimit=800 -jar supernode.jar log:

    
.   ____          _            __ _ _
/\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/  ___)| |_)| | | | | || (_| |  ) ) ) )
'  |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot ::        (v2.0.5.RELEASE)

2020-05-25 16:41:43.594 INFO 7069 --- [ main] ConfigServletWebServerApplicationContext : Refreshing org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@3f102e87: startup date [Mon May 25 16:41:43 CST 2020]; root of context hierarchy 2020-05-25 16:41:44.552 INFO 7069 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http) 2020-05-25 16:41:44.572 INFO 7069 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat] 2020-05-25 16:41:44.572 INFO 7069 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet Engine: Apache Tomcat/9.0.12 2020-05-25 16:41:44.579 INFO 7069 --- [ main] o.a.catalina.core.AprLifecycleListener : The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib] 2020-05-25 16:41:44.637 INFO 7069 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext 2020-05-25 16:41:44.637 INFO 7069 --- [ main] o.s.web.context.ContextLoader : Root WebApplicationContext: initialization completed in 1043 ms 2020-05-25 16:41:44.677 INFO 7069 --- [ main] o.s.b.w.servlet.ServletRegistrationBean : Servlet dispatcherServlet mapped to [/] 2020-05-25 16:41:44.680 INFO 7069 --- [ main] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'characterEncodingFilter' to: [/] 2020-05-25 16:41:44.680 INFO 7069 --- [ main] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'hiddenHttpMethodFilter' to: [/] 2020-05-25 16:41:44.680 INFO 7069 --- [ main] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'httpPutFormContentFilter' to: [/] 2020-05-25 16:41:44.680 INFO 7069 --- [ main] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'requestContextFilter' to: [/] 2020-05-25 16:41:45.212 INFO 7069 --- [ main] o.s.w.s.handler.SimpleUrlHandlerMapping : Mapped URL path [//favicon.ico] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler] 2020-05-25 16:41:45.328 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerAdapter : Looking for @ControllerAdvice: org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@3f102e87: startup date [Mon May 25 16:41:43 CST 2020]; root of context hierarchy 2020-05-25 16:41:45.384 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/checkpreload.htm],methods=[GET]}" onto public java.lang.String com.dragonflyoss.dragonfly.supernode.rest.controller.PreloadController.checkHealth() 2020-05-25 16:41:45.385 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/_ping],methods=[GET]}" onto public java.lang.String com.dragonflyoss.dragonfly.supernode.rest.controller.PreloadController.ping() 2020-05-25 16:41:45.388 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/peer/registry],methods=[POST]}" onto public com.dragonflyoss.dragonfly.supernode.common.view.ResultInfo com.dragonflyoss.dragonfly.supernode.rest.controller.PeerController.doRegistry(com.dragonflyoss.dragonfly.supernode.rest.request.RegistryRequest) 2020-05-25 16:41:45.388 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/peer/registry],methods=[POST],consumes=[application/json;charset=UTF-8 || application/json]}" onto public com.dragonflyoss.dragonfly.supernode.common.view.ResultInfo com.dragonflyoss.dragonfly.supernode.rest.controller.PeerController.doRegistryWithJson(com.dragonflyoss.dragonfly.supernode.rest.request.RegistryRequest) 2020-05-25 16:41:45.389 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/peer/service/down],methods=[GET]}" onto public com.dragonflyoss.dragonfly.supernode.common.view.ResultInfo com.dragonflyoss.dragonfly.supernode.rest.controller.PeerController.reportServiceDown(com.dragonflyoss.dragonfly.supernode.rest.request.ReportServiceDownRequest) 2020-05-25 16:41:45.389 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/peer/task],methods=[GET]}" onto public com.dragonflyoss.dragonfly.supernode.common.view.ResultInfo com.dragonflyoss.dragonfly.supernode.rest.controller.PeerController.pullPieceTask(com.dragonflyoss.dragonfly.supernode.rest.request.PullPieceTaskRequest) 2020-05-25 16:41:45.389 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/peer/piece/suc],methods=[GET]}" onto public com.dragonflyoss.dragonfly.supernode.common.view.ResultInfo com.dragonflyoss.dragonfly.supernode.rest.controller.PeerController.reportPiece(com.dragonflyoss.dragonfly.supernode.rest.request.ReportPieceRequest) 2020-05-25 16:41:45.391 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/preheats],methods=[GET]}" onto public org.springframework.http.ResponseEntity com.dragonflyoss.dragonfly.supernode.rest.controller.PreheatController.getPreheatTasks() 2020-05-25 16:41:45.391 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/preheats/{id}],methods=[GET]}" onto public org.springframework.http.ResponseEntity com.dragonflyoss.dragonfly.supernode.rest.controller.PreheatController.queryPreheatTask(java.lang.String) 2020-05-25 16:41:45.391 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/preheats/{id}],methods=[DELETE]}" onto public org.springframework.http.ResponseEntity com.dragonflyoss.dragonfly.supernode.rest.controller.PreheatController.deletePreheatTask(java.lang.String) 2020-05-25 16:41:45.391 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/preheats],methods=[POST]}" onto public org.springframework.http.ResponseEntity com.dragonflyoss.dragonfly.supernode.rest.controller.PreheatController.createPreheatTask(com.dragonflyoss.dragonfly.supernode.rest.request.PreheatCreateRequest) 2020-05-25 16:41:45.392 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/super/config],methods=[POST]}" onto public com.dragonflyoss.dragonfly.supernode.common.view.ResultInfo com.dragonflyoss.dragonfly.supernode.rest.controller.ConfigController.update(java.lang.Integer,java.lang.Boolean) 2020-05-25 16:41:45.394 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error],produces=[text/html]}" onto public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse) 2020-05-25 16:41:45.394 INFO 7069 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error]}" onto public org.springframework.http.ResponseEntity<java.util.Map<java.lang.String, java.lang.Object>> org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController.error(javax.servlet.http.HttpServletRequest) 2020-05-25 16:41:45.409 INFO 7069 --- [ main] o.s.w.s.handler.SimpleUrlHandlerMapping : Mapped URL path [/webjars/] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler] 2020-05-25 16:41:45.409 INFO 7069 --- [ main] o.s.w.s.handler.SimpleUrlHandlerMapping : Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler] 2020-05-25 16:41:45.419 INFO 7069 --- [ main] .m.m.a.ExceptionHandlerExceptionResolver : Detected @ExceptionHandler methods in globalExceptionHandler 2020-05-25 16:41:45.502 INFO 7069 --- [ main] o.s.j.e.a.AnnotationMBeanExporter : Registering beans for JMX exposure on startup 2020-05-25 16:41:45.535 INFO 7069 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path '' 2020-05-25 16:41:46.021 INFO 7069 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring FrameworkServlet 'dispatcherServlet' 2020-05-25 16:41:46.022 INFO 7069 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : FrameworkServlet 'dispatcherServlet': initialization started 2020-05-25 16:41:46.033 INFO 7069 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : FrameworkServlet 'dispatcherServlet': initialization completed in 11 ms


3. node
**client cmd:**
dfget -e 3600 --verbose --notbs -u http://1.1.1.1/20200525.txt -o /data0/20200525.txt --node 1.1.1.1,1.1.1.2,1.1.1.3

**client log:**

2020-05-25 18:16:36.650 WARN sign:8349-1590399001.198 : get item timeout(2s) from queue. 2020-05-25 18:16:37.146 WARN sign:37656-1590401521.706 : get item timeout(2s) from queue. 2020-05-25 18:16:38.650 WARN sign:8349-1590399001.198 : get item timeout(2s) from queue. 2020-05-25 18:16:39.146 WARN sign:37656-1590401521.706 : get item timeout(2s) from queue. 2020-05-25 18:16:41.146 WARN sign:37656-1590401521.706 : get item timeout(2s) from queue. 2020-05-25 18:16:42.460 WARN sign:8349-1590399001.198 : get item timeout(2s) from queue.



**Is the download slow because of the timeout of the queue?**
lowzj commented 4 years ago

Please use this command to get the whole logs of a task:

grep '37656-1590401521.706' $HOME/.small-dragonfly/logs/dfclient.log
111wang222 commented 4 years ago

Please use this command to get the whole logs of a task:

grep '37656-1590401521.706' $HOME/.small-dragonfly/logs/dfclient.log

run command:

grep '37656-1590401521.706' $HOME/.small-dragonfly/logs/dfclient.log
2020-05-25 18:24:26.578 INFO sign:23853-1590402121.311 : downloading piece:{"taskID":"d443be7ee1327a0af3ae29007d7d9727ac7d01799794daa2c7b8788f2086c1b7","superNode":"1.1.1.1","dstCid":"10.13.41.153-37656-1590401521.706","range":"654311424-662700031","result":503,"status":701,"pieceSize":8388608,"pieceNum":78}

there maybe the dfget version 0.3.2 too low， update supernode and dfget version to 1.0.2

There are still cases where downloading is slow, and there are stalls:

2020-05-26 15:50:58.005 INFO sign:5641-1590478673.882 : pull piece task({"taskID":"c6a9cda27d6309cc6c5d859b4a4727acaf62e4b2c2e05f60756bc6b2dd98142f","superNode":"1.1.1.1:8002","dstCid":"cdnnode:1.1.1.1~c6a9cda27d6309cc6c5d859b4a4727acaf62e4b2c2e05f60756bc6b2dd98142f","range":"3114270720-3129999359","result":503,"status":701,"pieceSize":15728640,"pieceNum":198}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.016s expected:1.547s
2020-05-26 15:50:58.369 INFO sign:13086-1590479161.907 : downloading piece:{"taskID":"ef43a15d9fc5b48ed9565d135309f06a408e3d151eedaed757cfc6a3823c8bbd","superNode":"1.1.1.3:8002","dstCid":"cdnnode:1.1.1.3~ef43a15d9fc5b48ed9565d135309f06a408e3d151eedaed757cfc6a3823c8bbd","range":"1163919360-1179647999","result":503,"status":701,"pieceSize":15728640,"pieceNum":74}
2020-05-26 15:50:58.389 INFO sign:13086-1590479161.907 : pull piece task({"taskID":"ef43a15d9fc5b48ed9565d135309f06a408e3d151eedaed757cfc6a3823c8bbd","superNode":"1.1.1.3:8002","dstCid":"cdnnode:1.1.1.3~ef43a15d9fc5b48ed9565d135309f06a408e3d151eedaed757cfc6a3823c8bbd","range":"1163919360-1179647999","result":503,"status":701,"pieceSize":15728640,"pieceNum":74}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.017s expected:1.002s
2020-05-26 15:50:59.190 INFO sign:13086-1590479161.907 : downloading piece:{"taskID":"ef43a15d9fc5b48ed9565d135309f06a408e3d151eedaed757cfc6a3823c8bbd","superNode":"1.1.1.3:8002","dstCid":"cdnnode:1.1.1.3~ef43a15d9fc5b48ed9565d135309f06a408e3d151eedaed757cfc6a3823c8bbd","range":"1289748480-1305477119","result":503,"status":701,"pieceSize":15728640,"pieceNum":82}
2020-05-26 15:50:59.203 INFO sign:13086-1590479161.907 : pull piece task({"taskID":"ef43a15d9fc5b48ed9565d135309f06a408e3d151eedaed757cfc6a3823c8bbd","superNode":"1.1.1.3:8002","dstCid":"cdnnode:1.1.1.3~ef43a15d9fc5b48ed9565d135309f06a408e3d151eedaed757cfc6a3823c8bbd","range":"1289748480-1305477119","result":503,"status":701,"pieceSize":15728640,"pieceNum":82}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.011s expected:1.517s

dont know why

xiezhw3 commented 4 years ago

I meet the same problem

111wang222 commented 4 years ago

I meet the same problem

maybe other peers cache be deleted， the client dont back source

xiezhw3 commented 4 years ago

@wangtenghe If client back to source, there will be a log like "download from source"?

lowzj commented 4 years ago

Could you please paste the whole logs of a downloading task?

111wang222 commented 4 years ago

Could you please paste the whole logs of a downloading task?

many downloaded tasks, and the following logs are queried according to task id:

2020-05-27 06:30:01.948 DEBU sign:9645-1590532201.947 : initProperties[/etc/dragonfly/dfget.yml] fail: failed to load yaml /etc/dragonfly/dfget.yml when reading file: open /etc/dragonfly/dfget.yml: no such file or directory
2020-05-27 06:30:01.948 DEBU sign:9645-1590532201.947 : initProperties[/etc/dragonfly.conf] fail: read ini config from /etc/dragonfly.conf error: open /etc/dragonfly.conf: no such file or directory
2020-05-27 06:30:01.948 INFO sign:9645-1590532201.947 : get cmd params:["dfget" "--timeout" "3600s" "--verbose" "--notbs" "-u" "http://1.2.5.64/indedata_1_2020052706.txt" "-o" "/data0/indedata_1_2020052706.txt" "--node" "1.2.5.63,1.2.5.64,1.1.42.30"]
2020-05-27 06:30:01.948 INFO sign:9645-1590532201.947 : get init config:{"url":"http://1.2.5.64/indedata_1_2020052706.txt","output":"/data0/indedata_1_2020052706.txt","timeout":3600000000000,"pattern":"p2p","notbs":true,"verbose":true,"nodes":["1.2.5.63:8002=1","1.2.5.64:8002=1","1.1.42.30:8002=1"],"localLimit":"20MB","minRate":"64KB","clientQueueSize":6,"workHome":"/root/.small-dragonfly","logConfig":{"maxSize":0,"maxBackups":0,"path":"/root/.small-dragonfly/logs/dfclient.log"}}
2020-05-27 06:30:01.948 INFO sign:9645-1590532201.947 : target file path:/data0/indedata_1_2020052706.txt
2020-05-27 06:30:01.950 INFO sign:9645-1590532201.947 : runtimeVariable: {"MetaPath":"/root/.small-dragonfly/meta/host.meta","SystemDataDir":"/root/.small-dragonfly/data","DataDir":"/root/.small-dragonfly/data","RealTarget":"/data0/indedata_1_2020052706.txt","StreamMode":false,"TargetDir":"/data0","TempTarget":"/data0/dfget-9645-1590532201.947.tmp-009183473","Cid":"1.1.16.78-9645-1590532201.947","TaskURL":"http://1.2.5.64/indedata_1_2020052706.txt","TaskFileName":"indedata_1_2020052706.txt-9645-1590532201.947","LocalIP":"1.1.16.78","PeerPort":0,"FileLength":-1,"DataExpireTime":180000000000,"ServerAliveTime":300000000000}
2020-05-27 06:30:01.951 INFO sign:9645-1590532201.947 : local http result:indedata_1_2020052706.txt-9645-1590532201.947 err:<nil>, port:16597 path:/check/
2020-05-27 06:30:01.951 INFO sign:9645-1590532201.947 : use peer server on port:16597
2020-05-27 06:30:01.951 INFO sign:9645-1590532201.947 : do register to one of [1.2.5.64:8002 1.1.42.30:8002 1.2.5.63:8002 1.2.5.64:8002 1.1.42.30:8002 1.2.5.63:8002]
2020-05-27 06:30:01.954 INFO sign:9645-1590532201.947 : do register to 1.2.5.64:8002, res:{"code":200,"msg":"success","data":{"taskId":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","fileLength":-1,"pieceSize":4194304,"cdnSource":"supernode","asSeed":false,"seedTaskID":""}} error:<nil>
2020-05-27 06:30:01.954 INFO sign:9645-1590532201.947 : do register result:{"code":200,"msg":"success","data":{"taskId":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","fileLength":-1,"pieceSize":4194304,"cdnSource":"supernode","asSeed":false,"seedTaskID":""}} and cost:0.003s
2020-05-27 06:30:01.954 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"","range":"","result":502,"status":700,"pieceSize":0,"pieceNum":0}
2020-05-27 06:30:01.954 INFO sign:9645-1590532201.947 : do register to 1.2.5.64:8002, res:{"code":200,"msg":"success","data":{"taskId":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","fileLength":-1,"pieceSize":4194304,"cdnSource":"supernode","asSeed":false,"seedTaskID":""}} error:<nil>
2020-05-27 06:30:01.954 INFO sign:9645-1590532201.947 : do register result:{"code":200,"msg":"success","data":{"taskId":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","fileLength":-1,"pieceSize":4194304,"cdnSource":"supernode","asSeed":false,"seedTaskID":""}} and cost:0.003s
2020-05-27 06:30:01.954 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"","range":"","result":502,"status":700,"pieceSize":0,"pieceNum":0}
2020-05-27 06:30:02.527 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}
2020-05-27 06:30:02.602 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.056s expected:0.056s
2020-05-27 06:30:02.746 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.133s expected:0.133s
2020-05-27 06:30:03.072 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.312s expected:0.312s
2020-05-27 06:30:03.705 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.619s expected:0.619s
2020-05-27 06:30:05.295 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.578s expected:1.578s
2020-05-27 06:30:06.357 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.054s expected:1.054s
2020-05-27 06:30:07.491 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.127s expected:1.127s
2020-05-27 06:30:08.981 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.480s expected:1.480s
2020-05-27 06:30:10.299 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.307s expected:1.307s
2020-05-27 06:30:11.727 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.421s expected:1.421s
2020-05-27 06:30:12.748 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.014s expected:1.014s
2020-05-27 06:30:14.024 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.269s expected:1.269s
2020-05-27 06:30:15.311 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.277s expected:1.277s
2020-05-27 06:30:16.308 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.985s expected:0.985s
2020-05-27 06:30:17.645 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.322s expected:1.322s
2020-05-27 06:30:18.707 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.050s expected:1.050s
2020-05-27 06:30:19.687 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.973s expected:0.973s
2020-05-27 06:30:20.792 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.094s expected:1.094s
2020-05-27 06:30:22.073 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.266s expected:1.266s
2020-05-27 06:30:23.681 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.599s expected:1.599s
2020-05-27 06:30:24.714 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.024s expected:1.024s
2020-05-27 06:30:25.914 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"1.2.4.148-6565-1590531604.289","range":"281018368-285212671","result":500,"status":701,"pieceSize":0,"pieceNum":0}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.189s expected:1.189s
2020-05-27 06:30:25.927 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"2323644416-2327838719","pieceNum":554,"pieceSize":4194304,"pieceMd5":"0f2d302c955723feeb97a7e1d0d29d8f:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:26.020 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"2323644416-2327838719","result":503,"status":701,"pieceSize":4194304,"pieceNum":554}
2020-05-27 06:30:26.031 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"6207569920-6211764223","pieceNum":1480,"pieceSize":4194304,"pieceMd5":"362808c36b4bb45b20f13522007c063f:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0} {"range":"6211764224-6215958527","pieceNum":1481,"pieceSize":4194304,"pieceMd5":"2d02dab61816ffdd254b2a085044f2b6:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:26.134 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6211764224-6215958527","result":503,"status":701,"pieceSize":4194304,"pieceNum":1481}
2020-05-27 06:30:26.145 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"6215958528-6220152831","pieceNum":1482,"pieceSize":4194304,"pieceMd5":"7878737e523b10705c166e254fdf75b4:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:26.145 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6207569920-6211764223","result":503,"status":701,"pieceSize":4194304,"pieceNum":1480}
2020-05-27 06:30:26.160 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6207569920-6211764223","result":503,"status":701,"pieceSize":4194304,"pieceNum":1480}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:1.474s
2020-05-27 06:30:26.170 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6207569920-6211764223","result":503,"status":701,"pieceSize":4194304,"pieceNum":1480}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:0.845s
2020-05-27 06:30:26.179 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6207569920-6211764223","result":503,"status":701,"pieceSize":4194304,"pieceNum":1480}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:1.455s
2020-05-27 06:30:26.244 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6207569920-6211764223","result":503,"status":701,"pieceSize":4194304,"pieceNum":1480}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.055s expected:0.849s
2020-05-27 06:30:26.254 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}
2020-05-27 06:30:27.291 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.026s expected:1.026s
2020-05-27 06:30:28.321 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.020s expected:1.020s
2020-05-27 06:30:29.702 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.373s expected:1.373s
2020-05-27 06:30:31.281 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.564s expected:1.564s
2020-05-27 06:30:32.661 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.371s expected:1.371s
2020-05-27 06:30:33.670 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.001s expected:1.001s
2020-05-27 06:30:35.043 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.365s expected:1.365s
2020-05-27 06:30:36.567 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.515s expected:1.515s
2020-05-27 06:30:38.134 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.554s expected:1.554s
2020-05-27 06:30:39.541 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.396s expected:1.396s
2020-05-27 06:30:40.580 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.027s expected:1.027s
2020-05-27 06:30:41.847 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.255s expected:1.255s
2020-05-27 06:30:43.353 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.497s expected:1.497s
2020-05-27 06:30:44.724 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.361s expected:1.361s
2020-05-27 06:30:46.204 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.468s expected:1.468s
2020-05-27 06:30:47.398 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6215958528-6220152831","result":503,"status":701,"pieceSize":4194304,"pieceNum":1482}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.171s expected:1.171s
2020-05-27 06:30:47.407 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"6916407296-6920601599","pieceNum":1649,"pieceSize":4194304,"pieceMd5":"9ece0d4b6f02e6689cd1ade21db3f755:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:47.497 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6916407296-6920601599","result":503,"status":701,"pieceSize":4194304,"pieceNum":1649}
2020-05-27 06:30:47.540 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"6920601600-6924795903","pieceNum":1650,"pieceSize":4194304,"pieceMd5":"9f3f7eeddf9527509568f3d3fcb85e6b:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:47.629 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6920601600-6924795903","result":503,"status":701,"pieceSize":4194304,"pieceNum":1650}
2020-05-27 06:30:47.651 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6920601600-6924795903","result":503,"status":701,"pieceSize":4194304,"pieceNum":1650}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:0.817s
2020-05-27 06:30:47.662 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6920601600-6924795903","result":503,"status":701,"pieceSize":4194304,"pieceNum":1650}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:0.923s
2020-05-27 06:30:48.802 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6920601600-6924795903","result":503,"status":701,"pieceSize":4194304,"pieceNum":1650}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.130s expected:1.130s
2020-05-27 06:30:50.395 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6920601600-6924795903","result":503,"status":701,"pieceSize":4194304,"pieceNum":1650}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.581s expected:1.581s
2020-05-27 06:30:51.647 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"6920601600-6924795903","result":503,"status":701,"pieceSize":4194304,"pieceNum":1650}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.243s expected:1.243s
2020-05-27 06:30:51.655 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"7029653504-7033847807","pieceNum":1676,"pieceSize":4194304,"pieceMd5":"85e7e61129089d97e0231471ab9e4003:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:51.768 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7029653504-7033847807","result":503,"status":701,"pieceSize":4194304,"pieceNum":1676}
2020-05-27 06:30:51.777 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7029653504-7033847807","result":503,"status":701,"pieceSize":4194304,"pieceNum":1676}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:1.161s
2020-05-27 06:30:51.788 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"7033847808-7038042111","pieceNum":1677,"pieceSize":4194304,"pieceMd5":"70e9a56c8deeecb10cd7f9fde495ed42:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:51.874 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7033847808-7038042111","result":503,"status":701,"pieceSize":4194304,"pieceNum":1677}
2020-05-27 06:30:51.885 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"7038042112-7042236415","pieceNum":1678,"pieceSize":4194304,"pieceMd5":"41fba5cfc56ceca281c46f223c60c878:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:51.970 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7038042112-7042236415","result":503,"status":701,"pieceSize":4194304,"pieceNum":1678}
2020-05-27 06:30:51.981 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"7042236416-7046430719","pieceNum":1679,"pieceSize":4194304,"pieceMd5":"4f27f45e1396139b04674d489c7b6f96:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:52.076 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7042236416-7046430719","result":503,"status":701,"pieceSize":4194304,"pieceNum":1679}
2020-05-27 06:30:52.089 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"7046430720-7050625023","pieceNum":1680,"pieceSize":4194304,"pieceMd5":"014924597234f9205b155d01aea0dadf:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:52.189 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7046430720-7050625023","result":503,"status":701,"pieceSize":4194304,"pieceNum":1680}
2020-05-27 06:30:52.201 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"7050625024-7054819327","pieceNum":1681,"pieceSize":4194304,"pieceMd5":"7f7e402e4b64e2a3c71e25c239b4a110:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:52.365 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7050625024-7054819327","result":503,"status":701,"pieceSize":4194304,"pieceNum":1681}
2020-05-27 06:30:52.377 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"7054819328-7059013631","pieceNum":1682,"pieceSize":4194304,"pieceMd5":"b0eb80ab58506d6304218e235185a85f:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:52.599 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7054819328-7059013631","result":503,"status":701,"pieceSize":4194304,"pieceNum":1682}
2020-05-27 06:30:52.610 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"7059013632-7063207935","pieceNum":1683,"pieceSize":4194304,"pieceMd5":"f56f67483891baab0a6248fbfece165c:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:52.832 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7059013632-7063207935","result":503,"status":701,"pieceSize":4194304,"pieceNum":1683}
2020-05-27 06:30:52.841 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"7063207936-7067402239","pieceNum":1684,"pieceSize":4194304,"pieceMd5":"a65817ab599c7c489c13d73bf39028e5:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:53.062 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7063207936-7067402239","result":503,"status":701,"pieceSize":4194304,"pieceNum":1684}
2020-05-27 06:30:53.073 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"7067402240-7071596543","pieceNum":1685,"pieceSize":4194304,"pieceMd5":"3ca9e70ce849b77201f02615c16dfab7:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:53.296 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7067402240-7071596543","result":503,"status":701,"pieceSize":4194304,"pieceNum":1685}
2020-05-27 06:30:53.309 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7067402240-7071596543","result":503,"status":701,"pieceSize":4194304,"pieceNum":1685}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:0.908s
2020-05-27 06:30:53.323 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7067402240-7071596543","result":503,"status":701,"pieceSize":4194304,"pieceNum":1685}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:0.820s
2020-05-27 06:30:53.331 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"7071596544-7075790847","pieceNum":1686,"pieceSize":4194304,"pieceMd5":"0b36ac3fd0b19024bb0bc3404839e383:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 06:30:53.544 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7071596544-7075790847","result":503,"status":701,"pieceSize":4194304,"pieceNum":1686}
2020-05-27 06:30:53.558 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7071596544-7075790847","result":503,"status":701,"pieceSize":4194304,"pieceNum":1686}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:1.545s
2020-05-27 06:30:53.569 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7071596544-7075790847","result":503,"status":701,"pieceSize":4194304,"pieceNum":1686}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:0.834s
2020-05-27 06:30:53.580 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7071596544-7075790847","result":503,"status":701,"pieceSize":4194304,"pieceNum":1686}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:1.206s
2020-05-27 06:30:53.591 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"155189248-159383551","pieceNum":37,"pieceSize":4194304,"pieceMd5":"2068312aa7f1d20a9345c1c149a296b5:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]

there about 5000 lines, your comment is too long (maximum is 65536 characters).

2020-05-27 07:29:46.894 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"11928600576-11932794879","result":503,"status":701,"pieceSize":4194304,"pieceNum":2844}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:0.821s
2020-05-27 07:29:48.083 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"11928600576-11932794879","result":503,"status":701,"pieceSize":4194304,"pieceNum":2844}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.153s expected:1.153s
2020-05-27 07:29:48.994 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"11928600576-11932794879","result":503,"status":701,"pieceSize":4194304,"pieceNum":2844}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.852s expected:0.852s
2020-05-27 07:29:49.034 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"7759462400-7763656703","pieceNum":1850,"pieceSize":4194304,"pieceMd5":"9d15b12e97fb0387a906b6515459ec7d:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 07:29:49.135 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"7759462400-7763656703","result":503,"status":701,"pieceSize":4194304,"pieceNum":1850}
2020-05-27 07:29:49.173 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"12062818304-12067012607","pieceNum":2876,"pieceSize":4194304,"pieceMd5":"6c8e237ac97cd2424c64a270b5b63f90:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 07:29:49.261 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12062818304-12067012607","result":503,"status":701,"pieceSize":4194304,"pieceNum":2876}
2020-05-27 07:29:49.294 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12062818304-12067012607","result":503,"status":701,"pieceSize":4194304,"pieceNum":2876}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:0.821s
2020-05-27 07:29:49.340 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12062818304-12067012607","result":503,"status":701,"pieceSize":4194304,"pieceNum":2876}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:0.915s
2020-05-27 07:29:50.474 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12062818304-12067012607","result":503,"status":701,"pieceSize":4194304,"pieceNum":2876}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.085s expected:1.085s
2020-05-27 07:29:52.079 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12062818304-12067012607","result":503,"status":701,"pieceSize":4194304,"pieceNum":2876}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.551s expected:1.551s
2020-05-27 07:29:53.457 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12062818304-12067012607","result":503,"status":701,"pieceSize":4194304,"pieceNum":2876}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.336s expected:1.336s
2020-05-27 07:29:54.298 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12062818304-12067012607","result":503,"status":701,"pieceSize":4194304,"pieceNum":2876}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.805s expected:0.805s
2020-05-27 07:29:55.506 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12062818304-12067012607","result":503,"status":701,"pieceSize":4194304,"pieceNum":2876}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.153s expected:1.153s
2020-05-27 07:29:56.562 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12062818304-12067012607","result":503,"status":701,"pieceSize":4194304,"pieceNum":2876}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.014s expected:1.014s
2020-05-27 07:29:56.600 DEBU sign:9645-1590532201.947 : pieces to be processed:[{"range":"12473860096-12478054399","pieceNum":2974,"pieceSize":4194304,"pieceMd5":"22a2ca39ca73dbd1d43ac2ffa5d14680:4194304","cid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","peerIp":"1.2.5.64","peerPort":8001,"path":"/download/213/2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","downLink":0}]
2020-05-27 07:29:56.715 INFO sign:9645-1590532201.947 : downloading piece:{"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12473860096-12478054399","result":503,"status":701,"pieceSize":4194304,"pieceNum":2974}
2020-05-27 07:29:56.748 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12473860096-12478054399","result":503,"status":701,"pieceSize":4194304,"pieceNum":2974}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.000s expected:1.121s
2020-05-27 07:29:57.750 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12473860096-12478054399","result":503,"status":701,"pieceSize":4194304,"pieceNum":2974}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:0.971s expected:0.971s
2020-05-27 07:29:59.003 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12473860096-12478054399","result":503,"status":701,"pieceSize":4194304,"pieceNum":2974}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.205s expected:1.205s
2020-05-27 07:30:00.612 INFO sign:9645-1590532201.947 : pull piece task({"taskID":"2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","superNode":"1.2.5.64:8002","dstCid":"cdnnode:1.2.5.64~2132ad3465796d45c7ae52d508f363a3cd4d2500adaff1e62f2cce245e2d313a","range":"12473860096-12478054399","result":503,"status":701,"pieceSize":4194304,"pieceNum":2974}) result:{"code":602,"msg":"{\"Code\":9,\"Msg\":\"peer should wait\"}"} and sleep actual:1.564s expected:1.564s

-.-; datafile 30GB , 3600s timeout ; after failed use rsync downfile. heart broken morning

lowzj commented 4 years ago

Here is an issue: #1117 about analysing the downloading speed and time.

And another suggestion, it's better to deploy supernode(including the nginx process) and file server separately.

111wang222 commented 4 years ago

In the end, I upgraded dfget 1.0.2 to solve the speed limit problem. I guess that under the speed limit, some tasks may take abnormally long download time or fail. The best case is to not limit the download speed of the client. Make sure that as few variables as possible interfere with the download task.

111wang222 commented 4 years ago

Here is an issue: #1117 about analysing the downloading speed and time.

And another suggestion, it's better to deploy supernode(including the nginx process) and file server separately.

This problem is not prominent when there is sufficient bandwidth, but it is a deployment problem. THKS! yoyoyo