Issues with iDrive e2: corrupted transfers

panomitrius · February 11, 2023, 1:38pm

What is the problem you are having with rclone?

After mounting my iDrive e2 with rclone and copying files to the mounted target, I get error messages.
I'm using MacOS Ventura 13.1 on a Macbook Air M1

Run the command 'rclone version' and share the full output of the command.

rclone v1.61.1

os/version: darwin 13.1 (64 bit)
os/kernel: 22.2.0 (arm64)
os/type: darwin
os/arch: arm64
go/version: go1.19.4
go/linking: dynamic
go/tags: cmount

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

iDrive e2

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

sudo rclone mount idrive:bucket1 /Users/Default/.rcloneMounts/BackisRclone --vfs-cache-max-size 20Gi --allow-other --daemon --log-file=rclonelog-2023-02-11.txt --log-level DEBUG

sudo ln -s /Users/Default/.rcloneMounts/BackisRclone /Volumes/BackisRclone

mv test.dmg /Volumes/BackisRclone

The rclone config contents with secrets removed.

[idrive]
type = s3
provider = IDrive
access_key_id = *****
secret_access_key = *****
acl = private
endpoint = ****.idrivee2-28.com

A log from the command with the `-vv` flag

2023/02/11 14:31:36 DEBUG : /: >Access: errc=0
2023/02/11 14:31:36 DEBUG : /: Getxattr: name="com.apple.bookmark.archive.prefer-home-relative-symlink"
2023/02/11 14:31:36 DEBUG : /: >Getxattr: errc=-78, value=""
2023/02/11 14:31:36 DEBUG : /: Access: mask=00
2023/02/11 14:31:36 DEBUG : /: >Access: errc=0
2023/02/11 14:31:36 DEBUG : /: Access: mask=00
2023/02/11 14:31:36 DEBUG : /: >Access: errc=0
2023/02/11 14:31:36 DEBUG : /: Statfs: 
2023/02/11 14:31:36 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/02/11 14:31:36 DEBUG : /: Access: mask=00
2023/02/11 14:31:36 DEBUG : /: >Access: errc=0
2023/02/11 14:31:36 DEBUG : test.dmg: multipart upload starting chunk 18 size 5Mi offset 85Mi/off
2023/02/11 14:31:36 DEBUG : test.dmg: multipart upload starting chunk 19 size 5Mi offset 90Mi/off
2023/02/11 14:31:36 DEBUG : /: Access: mask=01
2023/02/11 14:31:36 DEBUG : /: >Access: errc=0
2023/02/11 14:31:36 DEBUG : test.dmg: multipart upload starting chunk 20 size 5Mi offset 95Mi/off
2023/02/11 14:31:36 DEBUG : test.dmg: multipart upload starting chunk 21 size 119.500Ki offset 100Mi/off
2023/02/11 14:31:40 ERROR : test.dmg: WriteFileHandle.New Rcat failed: multipart upload corrupted: Etag differ: expecting 4c90189a5848c1cfef00cba06204efd8-21 but got 6be82b17b76da6477a391a698d2aebb7-21
2023/02/11 14:31:40 ERROR : test.dmg: WriteFileHandle.Flush error: multipart upload corrupted: Etag differ: expecting 4c90189a5848c1cfef00cba06204efd8-21 but got 6be82b17b76da6477a391a698d2aebb7-21
2023/02/11 14:31:40 ERROR : IO error: multipart upload corrupted: Etag differ: expecting 4c90189a5848c1cfef00cba06204efd8-21 but got 6be82b17b76da6477a391a698d2aebb7-21
2023/02/11 14:31:40 DEBUG : /test.dmg: >Flush: errc=-5
2023/02/11 14:31:40 DEBUG : /test.dmg: Release: fh=0x1
2023/02/11 14:31:40 DEBUG : test.dmg: WriteFileHandle.Release nothing to do
2023/02/11 14:31:40 DEBUG : /test.dmg: >Release: errc=0
2023/02/11 14:31:40 DEBUG : /test.dmg: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/02/11 14:31:40 DEBUG : /test.dmg: >Getattr: errc=0
2023/02/11 14:31:40 DEBUG : /test.dmg: Access: mask=00
2023/02/11 14:31:40 DEBUG : /test.dmg: >Access: errc=0

asdffdsa · February 11, 2023, 2:24pm

hi,

does this command work?
rclone copy test.dmg idrive:bucket1 -vv

panomitrius · February 11, 2023, 2:40pm

No, it's a similar error:

rclone copy test.dmg idrive:bucket1 -vv          
2023/02/11 15:38:43 DEBUG : rclone: Version "v1.61.1" starting with parameters ["rclone" "copy" "test.dmg" "idrive:bucket1" "-vv"]
2023/02/11 15:38:43 DEBUG : Creating backend with remote "test.dmg"
2023/02/11 15:38:43 DEBUG : Using config file from "/Users/Default/.config/rclone/rclone.conf"
2023/02/11 15:38:43 DEBUG : fs cache: adding new entry for parent of "test.dmg", "/Users/Default"
2023/02/11 15:38:43 DEBUG : Creating backend with remote "idrive:bucket1"
2023/02/11 15:38:43 DEBUG : test.dmg: Need to transfer - File not found at Destination
2023/02/11 15:38:47 DEBUG : test.dmg: md5 = 20bab6c33e3cb3d1d7007d3cf0c0d1a1 (Local file system at /Users/Default)
2023/02/11 15:38:47 DEBUG : test.dmg: md5 = 7a130f37c4c38deec93e6fec5d688985 (S3 bucket bucket1)
2023/02/11 15:38:47 ERROR : test.dmg: corrupted on transfer: md5 hash differ "20bab6c33e3cb3d1d7007d3cf0c0d1a1" vs "7a130f37c4c38deec93e6fec5d688985"
2023/02/11 15:38:47 INFO  : test.dmg: Removing failed copy
2023/02/11 15:38:48 ERROR : Attempt 1/3 failed with 1 errors and: corrupted on transfer: md5 hash differ "20bab6c33e3cb3d1d7007d3cf0c0d1a1" vs "7a130f37c4c38deec93e6fec5d688985"
2023/02/11 15:38:48 DEBUG : test.dmg: Need to transfer - File not found at Destination
2023/02/11 15:38:55 DEBUG : test.dmg: md5 = 20bab6c33e3cb3d1d7007d3cf0c0d1a1 (Local file system at /Users/Default)
2023/02/11 15:38:55 DEBUG : test.dmg: md5 = 0ec00d40c04ae8a05d1ce8d509572df9 (S3 bucket bucket1)
2023/02/11 15:38:55 ERROR : test.dmg: corrupted on transfer: md5 hash differ "20bab6c33e3cb3d1d7007d3cf0c0d1a1" vs "0ec00d40c04ae8a05d1ce8d509572df9"
2023/02/11 15:38:55 INFO  : test.dmg: Removing failed copy
2023/02/11 15:38:55 ERROR : Attempt 2/3 failed with 1 errors and: corrupted on transfer: md5 hash differ "20bab6c33e3cb3d1d7007d3cf0c0d1a1" vs "0ec00d40c04ae8a05d1ce8d509572df9"
2023/02/11 15:38:55 DEBUG : test.dmg: Need to transfer - File not found at Destination
2023/02/11 15:39:05 DEBUG : test.dmg: md5 = 20bab6c33e3cb3d1d7007d3cf0c0d1a1 (Local file system at /Users/Default)
2023/02/11 15:39:05 DEBUG : test.dmg: md5 = 48e07343dd2a68156257b877bca491f3 (S3 bucket bucket1)
2023/02/11 15:39:05 ERROR : test.dmg: corrupted on transfer: md5 hash differ "20bab6c33e3cb3d1d7007d3cf0c0d1a1" vs "48e07343dd2a68156257b877bca491f3"
2023/02/11 15:39:05 INFO  : test.dmg: Removing failed copy
2023/02/11 15:39:05 ERROR : Attempt 3/3 failed with 1 errors and: corrupted on transfer: md5 hash differ "20bab6c33e3cb3d1d7007d3cf0c0d1a1" vs "48e07343dd2a68156257b877bca491f3"
2023/02/11 15:39:05 INFO  : 
Transferred:   	  300.350 MiB / 300.350 MiB, 100%, 13.823 MiB/s, ETA 0s
Errors:                 1 (retrying may help)
Elapsed time:        21.8s

2023/02/11 15:39:05 DEBUG : 7 go routines active
2023/02/11 15:39:05 Failed to copy: corrupted on transfer: md5 hash differ "20bab6c33e3cb3d1d7007d3cf0c0d1a1" vs "48e07343dd2a68156257b877bca491f3"

asdffdsa · February 11, 2023, 2:49pm

ok, so let's test using rclone copy, not rclone mount

not sure exacly what is happening in that debug log.
as should see log entries such as
DEBUG : test.dmg: multipart upload starting chunk 119 size 5Mi offset 590Mi/1Gi

can you post the output of this, not using multi-part
rclone copy test.dmg idrive:bucket1 -vv --retries=1 --s3-upload-cutoff=5G

panomitrius · February 11, 2023, 3:02pm

Sure!

Here's the result:

rclone copy test.dmg idrive:bucket1 -vv --retries=1 --s3-upload-cutoff=5G
2023/02/11 16:01:21 DEBUG : rclone: Version "v1.61.1" starting with parameters ["rclone" "copy" "test.dmg" "idrive:bucket1" "-vv" "--retries=1" "--s3-upload-cutoff=5G"]
2023/02/11 16:01:21 DEBUG : Creating backend with remote "test.dmg"
2023/02/11 16:01:21 DEBUG : Using config file from "/Users/Default/.config/rclone/rclone.conf"
2023/02/11 16:01:21 DEBUG : fs cache: adding new entry for parent of "test.dmg", "/Users/Default"
2023/02/11 16:01:21 DEBUG : Creating backend with remote "idrive:bucket1"
2023/02/11 16:01:21 DEBUG : idrive: detected overridden config - adding "{yt53c}" suffix to name
2023/02/11 16:01:21 DEBUG : fs cache: renaming cache item "idrive:bucket1" to be canonical "idrive{yt53c}:bucket1"
2023/02/11 16:01:21 DEBUG : test.dmg: Need to transfer - File not found at Destination
2023/02/11 16:01:24 DEBUG : test.dmg: md5 = 20bab6c33e3cb3d1d7007d3cf0c0d1a1 (Local file system at /Users/Default)
2023/02/11 16:01:24 DEBUG : test.dmg: md5 = 439307a9749bba3ff18b2ac3678b2a87 (S3 bucket bucket1)
2023/02/11 16:01:24 ERROR : test.dmg: corrupted on transfer: md5 hash differ "20bab6c33e3cb3d1d7007d3cf0c0d1a1" vs "439307a9749bba3ff18b2ac3678b2a87"
2023/02/11 16:01:24 INFO  : test.dmg: Removing failed copy
2023/02/11 16:01:24 ERROR : Attempt 1/1 failed with 1 errors and: corrupted on transfer: md5 hash differ "20bab6c33e3cb3d1d7007d3cf0c0d1a1" vs "439307a9749bba3ff18b2ac3678b2a87"
2023/02/11 16:01:24 INFO  : 
Transferred:   	  100.117 MiB / 100.117 MiB, 100%, 33.366 MiB/s, ETA 0s
Errors:                 1 (retrying may help)
Elapsed time:         3.3s

2023/02/11 16:01:24 DEBUG : 7 go routines active
2023/02/11 16:01:24 Failed to copy: corrupted on transfer: md5 hash differ "20bab6c33e3cb3d1d7007d3cf0c0d1a1" vs "439307a9749bba3ff18b2ac3678b2a87"

asdffdsa · February 11, 2023, 4:23pm

the common issue seems to be corrupted on transfer, no sure why

just now, i did two quick tests, was able to upload a file to idrive, with and without multi-part

what i would try next, create a empty text file and try to copy that.

panomitrius · February 11, 2023, 6:04pm

Same issue with a completely blank txt file:

touch test.txt
rclone copy test.txt idrive:bucket1 -vv --retries=1 --s3-upload-cutoff=5G

2023/02/11 19:03:17 DEBUG : rclone: Version "v1.61.1" starting with parameters ["rclone" "copy" "test.txt" "idrive:bucket1" "-vv" "--retries=1" "--s3-upload-cutoff=5G"]
2023/02/11 19:03:17 DEBUG : Creating backend with remote "test.txt"
2023/02/11 19:03:17 DEBUG : Using config file from "/Users/Default/.config/rclone/rclone.conf"
2023/02/11 19:03:17 DEBUG : fs cache: adding new entry for parent of "test.txt", "/Users/Default"
2023/02/11 19:03:17 DEBUG : Creating backend with remote "idrive:bucket1"
2023/02/11 19:03:17 DEBUG : idrive: detected overridden config - adding "{yt53c}" suffix to name
2023/02/11 19:03:17 DEBUG : fs cache: renaming cache item "idrive:bucket1" to be canonical "idrive{yt53c}:bucket1"
2023/02/11 19:03:18 DEBUG : test.txt: Need to transfer - File not found at Destination
2023/02/11 19:03:19 DEBUG : test.txt: md5 = d41d8cd98f00b204e9800998ecf8427e (Local file system at /Users/Default)
2023/02/11 19:03:19 DEBUG : test.txt: md5 = 7dd27276cdaa47fe9432b60c0f5dbb7e (S3 bucket bucket1)
2023/02/11 19:03:19 ERROR : test.txt: corrupted on transfer: md5 hash differ "d41d8cd98f00b204e9800998ecf8427e" vs "7dd27276cdaa47fe9432b60c0f5dbb7e"
2023/02/11 19:03:19 INFO  : test.txt: Removing failed copy
2023/02/11 19:03:19 ERROR : Attempt 1/1 failed with 1 errors and: corrupted on transfer: md5 hash differ "d41d8cd98f00b204e9800998ecf8427e" vs "7dd27276cdaa47fe9432b60c0f5dbb7e"
2023/02/11 19:03:19 INFO  : 
Transferred:   	          0 B / 0 B, -, 0 B/s, ETA -
Errors:                 1 (retrying may help)
Elapsed time:         1.4s

2023/02/11 19:03:19 DEBUG : 7 go routines active
2023/02/11 19:03:19 Failed to copy: corrupted on transfer: md5 hash differ "d41d8cd98f00b204e9800998ecf8427e" vs "7dd27276cdaa47fe9432b60c0f5dbb7e"

panomitrius · February 11, 2023, 11:16pm

I had turned on server side encryption, when I turned that off it started working..

Raghava · February 12, 2023, 12:16am

Hi, Raghava from IDrive e2 team..

For encrypted buckets you need to set following line in your config; please follow the document for the notes.

server_side_encryption = aws:kms

Muhammad_Abrar · February 12, 2023, 4:32am

Created a pull request (Update s3.go by MuhammadAbrar1984 · Pull Request #6762 · rclone/rclone · GitHub) to fix this in rclone

system · February 15, 2023, 4:32am

This topic was automatically closed 3 days after the last reply. New replies are no longer allowed.