Rclone copy appears to be broken

What is the problem you are having with rclone?

I've been using some automation scripting for migrating data between two swift clusters. Until today, my rclone copy commands have worked fine, but now it apprears that rclone is requiring that the destination server needs a copy of the file being copied or it will fail outright.

What is your rclone version (output from rclone version)

rclone v1.52.2-276-gc2f3949d-beta

  • os/arch: linux/amd64
  • go version: go1.14.6

Which OS you are using and how many bits (eg Windows 7, 64 bit)

Cent 7.7

Which cloud storage system are you using? (eg Google Drive)

Swift

The command you were trying to run (eg rclone copy /tmp remote:tmp)

# rclone copy "newuat":"1-content-1" "newqatuat":"1-content-1" --no-check-certificate --no-check-dest --use-mmap --buffer-size 299M --files-from "1-content-1~~~aa" --stats 1m --stats-one-line-date --size-only --checkers=1 --transfers=20 --cache-tmp-upload-path /mnt/shared/rclone_tmp --no-traverse -P 
2020-07-31 00:47:07 ERROR : 0000fsqf1.content: Failed to copy: Object Not Found
2020-07-31 00:47:07 ERROR : Attempt 1/3 failed with 1 errors and: Object Not Found
2020-07-31 00:47:07 ERROR : 0000fsqf1.content: Failed to copy: Object Not Found
2020-07-31 00:47:07 ERROR : Attempt 2/3 failed with 1 errors and: Object Not Found
2020-07-31 00:47:08 ERROR : 0000fsqf1.content: Failed to copy: Object Not Found
2020-07-31 00:47:08 ERROR : Attempt 3/3 failed with 1 errors and: Object Not Found
2020/07/31 00:47:08 -         57 / 57 Bytes, 100%, 41 Bytes/s, ETA 0s
2020/07/31 00:47:08 Failed to copy: Object Not Found

The load balancer for the destination server newqatuat is showing the following 404s in logs:

10.143.138.58 - - [31/Jul/2020:00:47:06 +0000] "HEAD /v1/AUTH_uat/1-content-1 HTTP/1.1" 204 0 "http://newqatswiftlb-vip.localatlas.com/v1/AUTH_uat/1-content-1" "rclone/v1.52.2-276-gc2f3949d-beta" ua="10.131.170.5:443" rt=0.130 uct="0.001" uht="0.131" urt="0.131"
10.143.138.58 - - [31/Jul/2020:00:47:07 +0000] "GET /v1/AUTH_uat/1-content-1/0000fsqf1.content HTTP/1.1" 404 95 "http://newqatswiftlb-vip.localatlas.com/v1/AUTH_uat/1-content-1/0000fsqf1.content" "rclone/v1.52.2-276-gc2f3949d-beta" ua="10.131.170.1:443" rt=0.383 uct="0.001" uht="0.384" urt="0.384"
10.143.138.58 - - [31/Jul/2020:00:47:07 +0000] "GET /v1/AUTH_uat/1-content-1/0000fsqf1.content HTTP/1.1" 404 95 "http://newqatswiftlb-vip.localatlas.com/v1/AUTH_uat/1-content-1/0000fsqf1.content" "rclone/v1.52.2-276-gc2f3949d-beta" ua="10.131.170.6:443" rt=0.410 uct="0.002" uht="0.410" urt="0.410"
10.143.138.58 - - [31/Jul/2020:00:47:08 +0000] "GET /v1/AUTH_uat/1-content-1/0000fsqf1.content HTTP/1.1" 404 95 "http://newqatswiftlb-vip.localatlas.com/v1/AUTH_uat/1-content-1/0000fsqf1.content" "rclone/v1.52.2-276-gc2f3949d-beta" ua="10.131.170.2:443" rt=0.383 uct="0.001" uht="0.384" urt="0.384"

While the source is showing the relevant objects are present:

# rclone ls "newuat":"1-content-1"         
       19 0000fsqf1.content

lb-logs:
10.143.138.58 - - [31/Jul/2020:00:55:02 +0000] "GET /v1/AUTH_uat/1-content-1/0000fsqf1.content HTTP/1.1" 200 19 "http://newprodswiftlb-vip.localatlas.com/v1/AUTH_uat/1-content-1/0000fsqf1.content" "rclone/v1.52.2-276-gc2f3949d-beta" ua="10.128.170.2:443" rt=0.016 uct="0.001" uht="0.016" urt="0.016"

Configs:

[newuat]
type = swift
env_auth = false
user = uat
key = REDACTED
auth = http://newprodswiftlb-vip.localatlas.com/auth/v1.0
storage_url = http://newprodswiftlb-vip.localatlas.com/v1/AUTH_uat
endpoint_type = internal

[newqatuat]
type = swift
env_auth = false
user = uat
key = REDACTED
auth = http://newqatswiftlb-vip.localatlas.com/auth/v1.0
storage_url = http://newqatswiftlb-vip.localatlas.com/v1/AUTH_uat
endpoint_type = internal

A log from the command with the -vv flag

# rclone copy -vv "newuat":"1-content-1" "newqatuat":"1-content-1" --no-check-certificate --no-check-dest --use-mmap --buffer-size 299M --files-from "1-content-1~~~aa" --stats 1m --stats-one-line-date --size-only --checkers=1 --transfers=20 --cache-tmp-upload-path /mnt/shared/rclone_tmp --no-traverse -P 
2020/07/31 00:51:42 DEBUG : rclone: Version "v1.52.2-276-gc2f3949d-beta" starting with parameters ["rclone" "copy" "-vv" "newuat:1-content-1" "newqatuat:1-content-1" "--no-check-certificate" "--no-check-dest" "--use-mmap" "--buffer-size" "299M" "--files-from" "1-content-1~~~aa" "--stats" "1m" "--stats-one-line-date" "--size-only" "--checkers=1" "--transfers=20" "--cache-tmp-upload-path" "/mnt/shared/rclone_tmp" "--no-traverse" "-P"]
2020/07/31 00:51:42 DEBUG : Using config file from "/root/.config/rclone/rclone.conf"
2020-07-31 00:51:42 DEBUG : Swift container 1-content-1: Waiting for checks to finish
2020-07-31 00:51:42 DEBUG : Swift container 1-content-1: Waiting for transfers to finish
2020-07-31 00:51:43 ERROR : 0000fsqf1.content: Failed to copy: Object Not Found
2020-07-31 00:51:43 INFO  : There was nothing to transfer
2020-07-31 00:51:43 ERROR : Attempt 1/3 failed with 1 errors and: Object Not Found
2020-07-31 00:51:43 DEBUG : Swift container 1-content-1: Waiting for checks to finish
2020-07-31 00:51:43 DEBUG : Swift container 1-content-1: Waiting for transfers to finish
2020-07-31 00:51:43 ERROR : 0000fsqf1.content: Failed to copy: Object Not Found
2020-07-31 00:51:43 INFO  : There was nothing to transfer
2020-07-31 00:51:43 ERROR : Attempt 2/3 failed with 1 errors and: Object Not Found
2020-07-31 00:51:43 DEBUG : Swift container 1-content-1: Waiting for checks to finish
2020-07-31 00:51:43 DEBUG : Swift container 1-content-1: Waiting for transfers to finish
2020-07-31 00:51:43 ERROR : 0000fsqf1.content: Failed to copy: Object Not Found
2020-07-31 00:51:43 INFO  : There was nothing to transfer
2020-07-31 00:51:43 ERROR : Attempt 3/3 failed with 1 errors and: Object Not Found
2020/07/31 00:51:43 -         57 / 57 Bytes, 100%, 41 Bytes/s, ETA 0s
2020/07/31 00:51:43 INFO  : 2020/07/31 00:51:43 -         57 / 57 Bytes, 100%, 41 Bytes/s, ETA 0s

2020/07/31 00:51:43 DEBUG : 10 go routines active
2020/07/31 00:51:43 Failed to copy: Object Not Found

Rclone is also failing if the destination container doesnt exist:

# rclone copy qat:10514-pdf newqat:somerando-10514-pdf --no-check-certificate --no-check-dest --use-mmap --buffer-size 299M --stats 1m --stats-one-line-date --size-only --checkers=1 --transfers=20 --cache-tmp-upload-path /mnt/shared/rclone_tmp -P 
2020-07-31 01:04:48 ERROR : 0000j43in.pdf: Failed to copy: Container Not Found
2020-07-31 01:04:49 ERROR : 0000j43ip.pdf: Failed to copy: Container Not Found
2020-07-31 01:04:50 ERROR : 0000j43jo.pdf: Failed to copy: Container Not Found
2020-07-31 01:04:50 ERROR : 0000j43iq.pdf: Failed to copy: Container Not Found
2020-07-31 01:04:51 ERROR : 0000j43io.pdf: Failed to copy: Container Not Found
2020-07-31 01:04:51 ERROR : 0000j43jw.pdf: Failed to copy: Container Not Found
2020-07-31 01:04:52 ERROR : 0000j43js.pdf: Failed to copy: Container Not Found
2020-07-31 01:04:52 ERROR : 0000j43jq.pdf: Failed to copy: Container Not Found

Does the file newuat:1-content-1/0000fsqf1.content exist?

Maybe we can concentrate on that one file for the moment.

Does

rclone lsf newuat:1-content-1

show that file?

Does this successfully retreive the file?

rclone copyto -vv newuat:1-content-1/0000fsqf1.content /tmp/0000fsqf1.content

This is more likely because the source container doesn't exist. Does the container 10514-pdf exist? Can you rclone ls qat:10514-pdf?

Does the file `newuat:1-content-1/0000fsqf1.content` exist?

Yes, I've confirmed. It lists. It's downloadable. The file isn't corrupted. The load balancers report 20x for retrieving the file

0000fsqf1.content
[root@cxvlhgdj022]~# rclone download newuat:1-content-1/0000fsqf1.content
[root@cxvlhgdj022]~# rclone copy newuat:1-content-1/0000fsqf1.content .
[root@cxvlhgdj022]~# md5sum 0000fsqf1.content 
32999965d6fede05552ece7784241e22  0000fsqf1.content
This is more likely because the source container doesn't exist. Does the container 10514-pdf exist? 

I've confirmed the source exists.

[root@cxvlhgdj022]~# rclone ls qat:10514-pdf | head
   188494 0000j43in.pdf
   116180 0000j43io.pdf
    85340 0000j43ip.pdf
   346296 0000j43iq.pdf
   531503 0000j43jh.pdf
   119762 0000j43ji.pdf
    83136 0000j43jj.pdf
    90431 0000j43jk.pdf
    90693 0000j43jl.pdf
    82971 0000j43jm.pdf

The issue is not on the source side. Rclone is failing when trying to copy to the destination. If you look at the loadbalancer logs I provided, the rclone does a head check on the destination for the object or container, if it returns 404 on the destination rclone fails outright. I'm pretty sure this isn't the intended behavior from a migration perspective.

[root@cxvlhgdj022]~# rclone copy qat:10514-pdf newqatuat:10514-pdf
2020/07/31 15:52:15 ERROR : 0000j43in.pdf: Failed to copy: Container Not Found
2020/07/31 15:52:15 ERROR : 0000j43ip.pdf: Failed to copy: Container Not Found
2020/07/31 15:52:16 ERROR : 0000j43io.pdf: Failed to copy: Container Not Found
2020/07/31 15:52:16 ERROR : 0000j43iq.pdf: Failed to copy: Container Not Found
2020/07/31 15:52:17 ERROR : 0000j43jh.pdf: Failed to copy: Container Not Found
2020/07/31 15:52:18 ERROR : 0000j43ji.pdf: Failed to copy: Container Not Found
2020/07/31 15:52:18 ERROR : 0000j43jj.pdf: Failed to copy: Container Not Found
2020/07/31 15:52:19 ERROR : 0000j43jk.pdf: Failed to copy: Container Not Found
2020/07/31 15:52:20 ERROR : 0000j43jl.pdf: Failed to copy: Container Not Found

It is specifically failing because the container isn't present on the destination, not the source.

this is happening on every server

[root@cxvlhgdj022]~# rclone copy uat_uat:13770-native-j newqatuat:13770-native-j -P
2020-07-31 15:55:53 ERROR : 0000jtpbj.pdf: Failed to copy: Container Not Found
2020-07-31 15:55:54 ERROR : 0000kcmoj.docx: Failed to copy: Container Not Found
2020-07-31 15:55:54 ERROR : 0000kckhj.sxterm: Failed to copy: Container Not Found
2020-07-31 15:55:54 ERROR : Attempt 1/3 failed with 3 errors and: Container Not Found
2020-07-31 15:55:55 ERROR : 0000kckhj.sxterm: Failed to copy: Container Not Found
2020-07-31 15:55:56 ERROR : 0000jtpbj.pdf: Failed to copy: Container Not Found
2020-07-31 15:55:56 ERROR : 0000kcmoj.docx: Failed to copy: Container Not Found
2020-07-31 15:55:56 ERROR : Attempt 2/3 failed with 3 errors and: Container Not Found
2020-07-31 15:55:57 ERROR : 0000jtpbj.pdf: Failed to copy: Container Not Found
2020-07-31 15:55:58 ERROR : 0000kckhj.sxterm: Failed to copy: Container Not Found
Transferred:             0 / 22.842 kBytes, 0%, 0 Bytes/s, ETA -
Errors:                 2 (retrying may help)
Transferred:            0 / 1, 0%
Elapsed time:         6.2s
Transferring:
 *                                0000kcmoj.docx:  0% /22.842k, 0/s, -^C^

even with specifying --no-check-dest

[root@cxvlhgdj022]~# rclone copy uat_uat:13770-native-j newqatuat:13770-native-j --no-check-dest -P
2020-07-31 15:56:55 ERROR : 0000kcmoj.docx: Failed to copy: Container Not Found
2020-07-31 15:56:55 ERROR : 0000kckhj.sxterm: Failed to copy: Container Not Found
2020-07-31 15:56:56 ERROR : 0000jtpbj.pdf: Failed to copy: Container Not Found
2020-07-31 15:56:56 ERROR : Attempt 1/3 failed with 3 errors and: Container Not Found
2020-07-31 15:56:57 ERROR : 0000jtpbj.pdf: Failed to copy: Container Not Found
2020-07-31 15:56:57 ERROR : 0000kcmoj.docx: Failed to copy: Container Not Found
2020-07-31 15:56:58 ERROR : 0000kckhj.sxterm: Failed to copy: Container Not Found
2020-07-31 15:56:58 ERROR : Attempt 2/3 failed with 3 errors and: Container Not Found
Transferred:             0 / 2.637 kBytes, 0%, 0 Bytes/s, ETA -
Transferred:            0 / 3, 0%
Elapsed time:         4.2s
Transferring:
 *                                 0000jtpbj.pdf: transferring
 *                              0000kckhj.sxterm:  0% /2.637k, 0/s, -
 *                                0000kcmoj.docx: transferring^C

-- newfiles from newqatuat to uat_uat

# mkdir testuploads
# touch testupload/1.obj
# touch testupload/2.obj
# sswift upload testuploads testuploads
testuploads/2.obj
testuploads/1.obj
# sswift list
1-content-1
testuploads
# sswift list testuploads
testuploads/1.obj
testuploads/2.obj
# rclone ls newqatuat:testuploads
        0 testuploads/1.obj
        0 testuploads/2.obj
# rclone copy newqatuat:testuploads uat_uat:testuploads -P
Transferred:             0 / 0 Bytes, -, 0 Bytes/s, ETA -
Transferred:            2 / 2, 100%
Elapsed time:         1.4s

-- newfiles from uat_uat to newqatuat

# mkdir testuploads_otherway
# touch testuploads_otherway/1.obj
# touch testuploads_otherway/2.obj
# sswift upload testuploads_otherway testuploads_otherway
testuploads_otherway/2.obj
testuploads_otherway/1.obj
# sswift list testuploads_otherway
testuploads_otherway/1.obj
testuploads_otherway/2.obj
# rclone ls uat_uat:testuploads_otherway
        0 testuploads_otherway/1.obj
        0 testuploads_otherway/2.obj
# rclone copy uat_uat:testuploads newqatuat:testuploads -P
Transferred:             0 / 0 Bytes, -, 0 Bytes/s, ETA -
Checks:                 2 / 2, 100%
Elapsed time:         0.5s

-- old files from uat_uat to newqatuat

# rclone lsd uat_uat: | head
          38 2020-07-31 16:10:45         1 .swiftstack-web-console-metadata
          19 2020-07-31 16:10:45         1 1-content
          19 2020-07-31 16:10:45         1 1-content-1
       23227 2020-07-31 16:10:45         2 1-content-a
       22815 2020-07-31 16:10:45         1 1-content-h
        1569 2020-07-31 16:10:45         1 1-content-k
       23437 2020-07-31 16:10:45         2 1-native
       22113 2020-07-31 16:10:45         1 1-native-1
        1324 2020-07-31 16:10:45         1 1-native-4
      586099 2020-07-31 16:10:45         2 1-native-a
# rclone ls uat_uat:1-content-a
    10786 0000hgs5a.content
    12441 0000lqira.content
# rclone copy uat_uat:1-content-a newqatuat:1-content-a -P
2020-07-31 16:11:48 ERROR : 0000lqira.content: Failed to copy: Container Not Found
2020-07-31 16:11:48 ERROR : 0000hgs5a.content: Failed to copy: Container Not Found
2020-07-31 16:11:48 ERROR : Attempt 1/3 failed with 2 errors and: Container Not Found
2020-07-31 16:11:49 ERROR : 0000hgs5a.content: Failed to copy: Container Not Found
2020-07-31 16:11:50 ERROR : 0000lqira.content: Failed to copy: Container Not Found
2020-07-31 16:11:50 ERROR : Attempt 2/3 failed with 2 errors and: Container Not Found
2020-07-31 16:11:51 ERROR : 0000hgs5a.content: Failed to copy: Container Not Found
2020-07-31 16:11:51 ERROR : 0000lqira.content: Failed to copy: Container Not Found
2020-07-31 16:11:51 ERROR : Attempt 3/3 failed with 2 errors and: Container Not Found
Transferred:             0 / 0 Bytes, -, 0 Bytes/s, ETA -
Errors:                 2 (retrying may help)
Elapsed time:         4.7s
2020/07/31 16:11:51 Failed to copy with 2 errors: last error was: Container Not Found
# rclone copy uat_uat:'1-content-a' newqatuat:'1-content-a' -P
2020-07-31 16:12:28 ERROR : 0000hgs5a.content: Failed to copy: Container Not Found
2020-07-31 16:12:29 ERROR : 0000lqira.content: Failed to copy: Container Not Found
2020-07-31 16:12:29 ERROR : Attempt 1/3 failed with 2 errors and: Container Not Found
2020-07-31 16:12:29 ERROR : 0000hgs5a.content: Failed to copy: Container Not Found
2020-07-31 16:12:30 ERROR : 0000lqira.content: Failed to copy: Container Not Found
2020-07-31 16:12:30 ERROR : Attempt 2/3 failed with 2 errors and: Container Not Found
2020-07-31 16:12:31 ERROR : 0000hgs5a.content: Failed to copy: Container Not Found
2020-07-31 16:12:32 ERROR : 0000lqira.content: Failed to copy: Container Not Found
2020-07-31 16:12:32 ERROR : Attempt 3/3 failed with 2 errors and: Container Not Found
Transferred:             0 / 0 Bytes, -, 0 Bytes/s, ETA -
Errors:                 2 (retrying may help)
Elapsed time:         4.8s
2020/07/31 16:12:32 Failed to copy with 2 errors: last error was: Container Not Found

hmm maybe its the actual endpoint because the copy is going through for other endpoints

[root@cxvlhgdj022]~# rclone copy uat_uat:'1-content-a' uat_uat:'testupload' -P
Transferred:       22.683k / 22.683 kBytes, 100%, 20.849 kBytes/s, ETA 0s
Transferred:            2 / 2, 100%
Elapsed time:         1.6s
[root@cxvlhgdj022]~# rclone copy uat_uat:'1-content-a' qat:'testupload' -P
Transferred:       22.683k / 22.683 kBytes, 100%, 80.188 kBytes/s, ETA 0s
Transferred:            2 / 2, 100%
Elapsed time:         0.7s

yea appears to only be an issue using this endpoint as dest:

[root@cxvlhgdj022]~# rclone copy newqat:20059-content-2 qat:20059-content-2-test -P
Transferred:       14.994k / 14.994 kBytes, 100%, 52.985 kBytes/s, ETA 0s
Transferred:            2 / 2, 100%
Elapsed time:         0.7s
[root@cxvlhgdj022]~# rclone copy qat:20059-content-2-test newqat:20059-content-2-test-back -P
2020-07-31 16:26:14 ERROR : 0000lhp92.content: Failed to copy: Container Not Found
2020-07-31 16:26:15 ERROR : 0000lj9j2.content: Failed to copy: Container Not Found
2020-07-31 16:26:15 ERROR : Attempt 1/3 failed with 2 errors and: Container Not Found
2020-07-31 16:26:16 ERROR : 0000lhp92.content: Failed to copy: Container Not Found
2020-07-31 16:26:17 ERROR : 0000lj9j2.content: Failed to copy: Container Not Found
2020-07-31 16:26:17 ERROR : Attempt 2/3 failed with 2 errors and: Container Not Found
2020-07-31 16:26:18 ERROR : 0000lhp92.content: Failed to copy: Container Not Found
2020-07-31 16:26:18 ERROR : 0000lj9j2.content: Failed to copy: Container Not Found
2020-07-31 16:26:18 ERROR : Attempt 3/3 failed with 2 errors and: Container Not Found
Transferred:             0 / 0 Bytes, -, 0 Bytes/s, ETA -
Errors:                 2 (retrying may help)
Elapsed time:         4.9s
2020/07/31 16:26:18 Failed to copy with 2 errors: last error was: Container Not Found
[root@cxvlhgdj022]~# rclone ls  qat:20059-content-2-test 
    14771 0000lhp92.content
      583 0000lj9j2.content

any ideas / suggestions why rclone would only be working unidirectionally here?

Rclone does a HEAD request on an object to see if it exists before copying it - maybe it is already there and doesn't need copying.

Can you do the failing test with -vv --dump bodies --retries 1 --low-level-retries 1 and post the result? You might need to redact some sensitive info.

That should tell us exactly what is going on.