Rclone copy hangs and doesn't copy any object

Help and Support
1

Hi All,

While trying to copy bucket from Minio OBS to S3 - rclone will just copy several objects and hang.
it looks like the process is running waiting for some response but never gets it and stall.

-vv and --log-level - doesn’t supply any valuable info on what is going on

root@backup01:~# rclone -vv --buffer-size=2G --transfers=50 copy minio:xxxx01 S3:zzz-yyyy-backup02 |
2018/08/09 13:13:34 DEBUG : rclone: Version “v1.42” starting with parameters [“rclone” “-vv” “–buffer-size=2G” “–transfers=50” "copy|
" “minio:xxxx01” “S3:zzz-yyyy-backup02”] |
2018/08/09 13:13:34 DEBUG : Using config file from “/root/.rclone.conf” |
2018/08/09 13:13:37 DEBUG : abe113d3/verify/0/rw/5d36-4a6a-89aa-77f8495ed7f8: Modification times differ by -15h27m23s: 2018-08-09 10:1|
3:23 +0000 UTC, 2018-08-08 21:46:00 +0300 IDT |
2018/08/09 13:13:37 DEBUG : abe113d3/verify/103/rw/5d36-4a6a-89aa-77f8495ed7f8: Modification times differ by -15h26m38s: 2018-08-09 10
:14:18 +0000 UTC, 2018-08-08 21:47:40 +0300 IDT
2018/08/09 13:13:37 DEBUG : abe113d3/verify/62/rw/5d36-4a6a-89aa-77f8495ed7f8: Modification times differ by -15h26m28s: 2018-08-09 10:
13:53 +0000 UTC, 2018-08-08 21:47:25 +0300 IDT
2018/08/09 13:13:37 DEBUG : abe113d3/verify/100/rw/5d36-4a6a-89aa-77f8495ed7f8: Modification times differ by -15h26m23s: 2018-08-09 10
:14:17 +0000 UTC, 2018-08-08 21:47:54 +0300 IDT
2018/08/09 13:13:37 DEBUG : abe113d3/verify/63/rw/5d36-4a6a-89aa-77f8495ed7f8: Modification times differ by -15h26m44s: 2018-08-09 10:
14:15 +0000 UTC, 2018-08-08 21:47:31 +0300 IDT
2018/08/09 13:13:37 INFO : abe113d3/verify/103/rw/5d36-4a6a-89aa-77f8495ed7f8: Updated modification time in destination
2018/08/09 13:13:37 DEBUG : abe113d3/verify/103/rw/5d36-4a6a-89aa-77f8495ed7f8: Unchanged skipping
2018/08/09 13:13:37 INFO : abe113d3/verify/0/rw/5d36-4a6a-89aa-77f8495ed7f8: Updated modification time in destination
2018/08/09 13:13:37 DEBUG : abe113d3/verify/0/rw/5d36-4a6a-89aa-77f8495ed7f8: Unchanged skipping
2018/08/09 13:13:37 INFO : abe113d3/verify/62/rw/5d36-4a6a-89aa-77f8495ed7f8: Updated modification time in destination
2018/08/09 13:13:37 DEBUG : abe113d3/verify/62/rw/5d36-4a6a-89aa-77f8495ed7f8: Unchanged skipping
2018/08/09 13:13:37 INFO : abe113d3/verify/100/rw/5d36-4a6a-89aa-77f8495ed7f8: Updated modification time in destination
2018/08/09 13:13:37 DEBUG : abe113d3/verify/100/rw/5d36-4a6a-89aa-77f8495ed7f8: Unchanged skipping
2018/08/09 13:13:37 INFO : abe113d3/verify/63/rw/5d36-4a6a-89aa-77f8495ed7f8: Updated modification time in destination
2018/08/09 13:13:37 DEBUG : abe113d3/verify/63/rw/5d36-4a6a-89aa-77f8495ed7f8: Unchanged skipping
Transferred: 0 Bytes (0 Bytes/s)
Errors: 0
Checks: 5
Transferred: 0
Elapsed time: 1m0.1s

2018/08/09 13:15:34 INFO :
Transferred: 0 Bytes (0 Bytes/s)
Errors: 0
Checks: 5
Transferred: 0
Elapsed time: 2m0.1s

2

Strange…

Can you try with -vv --dump headers to see if there are http requests that don’t get a response.

Also you could try sending SIGQUIT to rclone (or press CTRL-\ ) and that will kill it with a full backtrace of running goroutines so we can see exactly what it is doing.

Note that if you use --transfers=50 and --buffer-size=2G you can potentially use 50*2G = 100G of RAM - was that what you intended?

3

This is what the server is waiting for:

2018/08/09 20:17:22 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2018/08/09 20:17:22 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2018/08/09 20:17:22 DEBUG : HTTP REQUEST (req 0xc4203cc700)
2018/08/09 20:17:22 DEBUG : GET /weka01?delimiter=%2F&marker=abe113d3%2Fd%2Fd%2F15%2F159%2F102724%2F&max-keys=1000&prefix=abe113d3%2Fd
%2Fd%2F15%2F159%2F HTTP/1.1
Host: weka2:9000
User-Agent: rclone/v1.42
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20180809T171722Z
Accept-Encoding: gzip

2018/08/09 20:17:22 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

4

Is there a way to control the HTTP timeout ?

5

Did you end up reducing the transfers and maybe the buffer-size too?

--timeout duration IO idle timeout (default 5m0s)

6

Hmm, that is a directory listing. It should return 1000 entries then return - it shouldn’t take ages.

You can try the --timeout parameter and also the --contimeout parameter - those might help.