rclone: corrupted on transfer: sizes differ 0 vs xxxx (s3 -> local)

The associated forum post URL from https://forum.rclone.org

n/a

What is the problem you are having with rclone?

Rclone fails to move most files from s3 to local disk with the error corrupted on transfer: sizes differ 0 vs xxxx. Some files are moved successfully.

What is your rclone version (output from rclone version)

The issue was first noticed after upgrading from 1.55.1 to 1.56.2. After downgrading back to 1.55.1 the errors stopped.

grep rclone /var/log/yum.log
Feb 03 03:30:17 Updated: rclone-1.53.4-1.x86_64
Mar 24 03:27:45 Updated: rclone-1.54.1-1.x86_64
May 05 03:21:08 Updated: rclone-1.55.1-1.x86_64
Oct 06 03:13:24 Updated: rclone-1.56.2-1.x86_64
Oct 15 21:45:25 Installed: rclone-1.55.1-1.x86_64

The errors started appearing on the first run after upgrading to 1.56.2 (see timestamps of yum.log vs count of “corrupt” in rclone logs):

root@hostname:~# fgrep corrupt /home/username/transfer_logs-incoming/rclone/* -c
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-05T220001.log:0
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-05T230000.log:0
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T000001.log:0
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T010001.log:0
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T020000.log:0
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T030000.log:0
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T040001.log:628
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T050001.log:3280
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T060001.log:7546
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T074515.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T093303.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T100001.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T110001.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T120001.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T130001.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T140001.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T150001.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T160001.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-06T170001.log:9988
[...]
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-15T150000.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-15T160000.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-15T170001.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-15T180000.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-15T190000.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-15T200000.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-15T210000.log:9988
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-15T220000.log:0
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-15T230000.log:0
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-16T000000.log:0
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-16T010000.log:0
/home/username/transfer_logs-incoming/rclone/rclone-2021-10-16T020001.log:0

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

Red Hat Enterprise Linux Server release 7.9 (Maipo) 3.10.0-1160.42.2.el7.x86_64

Which cloud storage system are you using? (e.g. Google Drive)

S3-compliant storage.

[src]
type = s3
provider = other
env_auth = false
access_key_id = xxx
secret_access_key = xxx
endpoint = xx.xxxx.xxx:10443

The command you were trying to run (e.g. rclone copy /tmp remote:tmp)

rclone: Version "v1.56.2" starting with parameters ["rclone" "move" "--min-age=30m" "--checkers=50" "--transfers=15" "--log-file=/home/username/transfer_logs-incoming/rclone/rclone-2021-10-14T000000.log" "--log-level=DEBUG" "src:srcconf/" "/nfs/directory/incoming/download_in_progress/"]

A log from the command with the -vv flag (e.g. output from rclone -vv copy /tmp remote:tmp)

2021/10/14 00:00:00 DEBUG : --min-age 30m0s to 2021-10-13 23:30:00.691982455 +0000 GMT m=-1799.954754214
2021/10/14 00:00:00 DEBUG : rclone: Version "v1.56.2" starting with parameters ["rclone" "move" "--min-age=30m" "--checkers=50" "--transfers=15" "--log-file=/home/username/transfer_logs-incoming/rclone/rclone-2021-10-14T000000.log" "--log-level=DEBUG" "src:srcconf/" "/nfs/directory/incoming/download_in_progress/"]
2021/10/14 00:00:00 DEBUG : Creating backend with remote "src:srcconf/"
2021/10/14 00:00:00 DEBUG : Using config file from "/home/username/.config/rclone/rclone.conf"
2021/10/14 00:00:00 DEBUG : fs cache: renaming cache item "src:srcconf/" to be canonical "src:srcconf"
2021/10/14 00:00:00 DEBUG : Creating backend with remote "/nfs/directory/incoming/download_in_progress/"
2021/10/14 00:01:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:       1m0.0s

2021/10/14 00:02:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:       2m0.0s

2021/10/14 00:03:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:       3m0.0s

2021/10/14 00:04:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:       4m0.0s

2021/10/14 00:05:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:       5m0.0s

2021/10/14 00:06:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:       6m0.0s

2021/10/14 00:07:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:       7m0.0s

2021/10/14 00:08:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:       8m0.0s

2021/10/14 00:09:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:       9m0.0s

2021/10/14 00:10:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:      10m0.0s

2021/10/14 00:11:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:      11m0.0s

2021/10/14 00:12:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:      12m0.0s

2021/10/14 00:13:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:      13m0.0s

2021/10/14 00:14:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:      14m0.0s

2021/10/14 00:15:00 INFO  :
Transferred:              0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time:      15m0.0s

2021/10/14 00:15:01 ERROR : 2021-10-06_2140833/2140833.x.gpg.md5: corrupted on transfer: sizes differ 0 vs 33
2021/10/14 00:15:01 INFO  : 2021-10-06_2140833/2140833.x.gpg.md5: Removing failed copy
2021/10/14 00:15:01 ERROR : 2021-10-06_2140833/2140833.x.gpg.md5: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 33
2021/10/14 00:15:01 ERROR : 2021-10-06_1818365/1818365.x.y.gpg.md5: corrupted on transfer: sizes differ 0 vs 33
2021/10/14 00:15:01 INFO  : 2021-10-06_1818365/1818365.x.y.gpg.md5: Removing failed copy
2021/10/14 00:15:01 ERROR : 2021-10-06_2140833/2140833.z.gz.q.md5: corrupted on transfer: sizes differ 0 vs 185
2021/10/14 00:15:01 INFO  : 2021-10-06_2140833/2140833.z.gz.q.md5: Removing failed copy
2021/10/14 00:15:01 ERROR : 2021-10-06_1818365/1818365.x.y.gpg.md5: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 33
2021/10/14 00:15:01 ERROR : 2021-10-06_2140833/2140833.z.gz.q.md5: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 185
2021/10/14 00:15:01 ERROR : 2021-10-06_2140833/2140833.x.md5: corrupted on transfer: sizes differ 0 vs 185
2021/10/14 00:15:01 INFO  : 2021-10-06_2140833/2140833.x.md5: Removing failed copy
2021/10/14 00:15:01 ERROR : 2021-10-06_2140833/2140833.z.gz.md5: corrupted on transfer: sizes differ 0 vs 181
2021/10/14 00:15:01 INFO  : 2021-10-06_2140833/2140833.z.gz.md5: Removing failed copy
2021/10/14 00:15:01 ERROR : 2021-10-06_2140833/2140833.x.md5: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 185
2021/10/14 00:15:01 ERROR : 2021-10-06_2140833/2140833.s.tar.gz.md5: corrupted on transfer: sizes differ 0 vs 180
2021/10/14 00:15:01 INFO  : 2021-10-06_2140833/2140833.s.tar.gz.md5: Removing failed copy
2021/10/14 00:15:01 ERROR : 2021-10-06_2140833/2140833.z.gz.md5: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 181
2021/10/14 00:15:01 ERROR : 2021-10-06_1818365/1818365.x.gpg.md5: corrupted on transfer: sizes differ 0 vs 33
2021/10/14 00:15:01 INFO  : 2021-10-06_1818365/1818365.x.gpg.md5: Removing failed copy
2021/10/14 00:15:01 ERROR : 2021-10-06_2140833/2140833.x.y.gpg.md5: corrupted on transfer: sizes differ 0 vs 33
[...]
2021/10/14 00:30:49 ERROR : 2021-10-06_5874950/5874950.z.gz.q.gpg: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 4037185
2021/10/14 00:30:50 ERROR : 2021-10-06_5265500/5265500.s.tar.gz.gpg: corrupted on transfer: sizes differ 0 vs 7000496
2021/10/14 00:30:50 INFO  : 2021-10-06_5265500/5265500.s.tar.gz.gpg: Removing failed copy
2021/10/14 00:30:50 ERROR : 2021-10-06_5265500/5265500.s.tar.gz.gpg: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 7000496
2021/10/14 00:30:50 ERROR : 2021-10-06_5875340/5875340.z.gz.q.gpg: corrupted on transfer: sizes differ 0 vs 4042184
2021/10/14 00:30:50 INFO  : 2021-10-06_5875340/5875340.z.gz.q.gpg: Removing failed copy
2021/10/14 00:30:50 ERROR : 2021-10-06_5875340/5875340.z.gz.q.gpg: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 4042184
2021/10/14 00:30:50 ERROR : 2021-10-06_5570730/5570730.s.tar.gz.gpg: corrupted on transfer: sizes differ 0 vs 6982951
2021/10/14 00:30:50 INFO  : 2021-10-06_5570730/5570730.s.tar.gz.gpg: Removing failed copy
2021/10/14 00:30:50 ERROR : 2021-10-06_5570730/5570730.s.tar.gz.gpg: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 6982951
2021/10/14 00:30:50 ERROR : 2021-10-06_5930824/5930824.z.gz.q.gpg: corrupted on transfer: sizes differ 0 vs 4039141
2021/10/14 00:30:50 INFO  : 2021-10-06_5930824/5930824.z.gz.q.gpg: Removing failed copy
2021/10/14 00:30:50 ERROR : 2021-10-06_5930824/5930824.z.gz.q.gpg: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 4039141
2021/10/14 00:30:50 ERROR : 2021-10-06_5490927/5490927.s.tar.gz.gpg: corrupted on transfer: sizes differ 0 vs 7025257
2021/10/14 00:30:50 INFO  : 2021-10-06_5490927/5490927.s.tar.gz.gpg: Removing failed copy
2021/10/14 00:30:50 ERROR : 2021-10-06_5490927/5490927.s.tar.gz.gpg: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 7025257
2021/10/14 00:30:50 ERROR : 2021-10-06_5877125/5877125.z.gz.q.gpg: corrupted on transfer: sizes differ 0 vs 4026912
2021/10/14 00:30:50 INFO  : 2021-10-06_5877125/5877125.z.gz.q.gpg: Removing failed copy
2021/10/14 00:30:50 ERROR : 2021-10-06_5877125/5877125.z.gz.q.gpg: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 4026912
2021/10/14 00:30:50 ERROR : 2021-10-06_5874950/5874950.s.tar.gz.gpg: corrupted on transfer: sizes differ 0 vs 7008193
2021/10/14 00:30:50 INFO  : 2021-10-06_5874950/5874950.s.tar.gz.gpg: Removing failed copy
2021/10/14 00:30:50 ERROR : 2021-10-06_5874950/5874950.s.tar.gz.gpg: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 7008193
2021/10/14 00:30:50 ERROR : 2021-10-06_5875340/5875340.s.tar.gz.gpg: corrupted on transfer: sizes differ 0 vs 7021153
2021/10/14 00:30:50 INFO  : 2021-10-06_5875340/5875340.s.tar.gz.gpg: Removing failed copy
2021/10/14 00:30:50 ERROR : 2021-10-06_5875340/5875340.s.tar.gz.gpg: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 7021153
2021/10/14 00:30:50 ERROR : 2021-10-06_5930824/5930824.s.tar.gz.gpg: corrupted on transfer: sizes differ 0 vs 6966945
2021/10/14 00:30:50 INFO  : 2021-10-06_5930824/5930824.s.tar.gz.gpg: Removing failed copy
2021/10/14 00:30:50 ERROR : 2021-10-06_5930824/5930824.s.tar.gz.gpg: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 6966945
2021/10/14 00:30:50 ERROR : 2021-10-06_5877125/5877125.s.tar.gz.gpg: corrupted on transfer: sizes differ 0 vs 6981619
2021/10/14 00:30:50 INFO  : 2021-10-06_5877125/5877125.s.tar.gz.gpg: Removing failed copy
2021/10/14 00:30:50 ERROR : 2021-10-06_5877125/5877125.s.tar.gz.gpg: Not deleting source as copy failed: corrupted on transfer: sizes differ 0 vs 6981619
2021/10/14 00:30:50 ERROR : Attempt 3/3 failed with 1664 errors and: corrupted on transfer: sizes differ 0 vs 6981619
2021/10/14 00:30:50 INFO  :
Transferred:        4.405Gi / 4.405 GiByte, 100%, 6.999 MiByte/s, ETA 0s
Errors:              1664 (retrying may help)
Checks:              4992 / 4992, 100%
Elapsed time:     30m49.6s

2021/10/14 00:30:50 DEBUG : 200 go routines active
2021/10/14 00:30:50 Failed to move with 1664 errors: last error was: corrupted on transfer: sizes differ 0 vs 6981619

How to use GitHub

  • Please use the 👍 reaction to show that you are affected by the same issue.
  • Please don’t comment if you have no relevant information to add. It’s just extra noise for everyone subscribed to this issue.
  • Subscribe to receive notifications on status change and new comments.

About this issue

  • Original URL
  • State: closed
  • Created 3 years ago
  • Reactions: 1
  • Comments: 22 (9 by maintainers)

Commits related to this issue

Most upvoted comments

The latest beta works 😃 Thanks a lot to all of you!!

@docuteam-kun thanks for the test account - that was really helpful.

I’ve managed to track down the cause of this bug.

Here is what I wrote in the commit message which explains it

s3: fix corrupted on transfer: sizes differ 0 vs xxxx with Ceph

In this commit, released in 1.56.0 we started reading the size of the object from the Content-Length header as returned by the GET request to read the object.

4401d180aabe5047 s3: add --s3-no-head-object

However some object storage systems, notably Ceph, don’t return a Content-Length header.

The new code correctly calls the setMetaData function with a nil pointer to the ContentLength.

However due to this commit from 2014, released in v1.18, the setMetaData function was not ignoring the size as it should have done.

0da6f242217aae7a s3: use official github.com/aws/aws-sdk-go including multipart upload #101

This commit correctly ignores the content length if not set.

So @olefrost you were spot on about the immediate cause of the problem but the bug wasn’t there as my initial code review showed, it’s been lying dormant since 2014!

So can you please try this @hakong and @docuteam-kun - thank you!

v1.57.0-beta.5805.a663f6338.fix-5732-s3-corrupt-on-transfer on branch fix-5732-s3-corrupt-on-transfer (uploaded in 15-30 mins)